Add pack runtime profiling hooks

2026-04-15 16:22:10 +02:00
parent ef7cdf2809
commit ba6af8115b
12 changed files with 696 additions and 3 deletions
--- a/src/PackLib/CMakeLists.txt
+++ b/src/PackLib/CMakeLists.txt
@@ -1,4 +1,4 @@
-file(GLOB_RECURSE FILE_SOURCES "*.h" "*.c" "*.cpp")
+file(GLOB_RECURSE FILE_SOURCES CONFIGURE_DEPENDS "*.h" "*.c" "*.cpp")

 add_library(PackLib STATIC ${FILE_SOURCES})

--- a/src/PackLib/M2Pack.cpp
+++ b/src/PackLib/M2Pack.cpp
@@ -1,6 +1,8 @@
 #include "M2Pack.h"
+#include "PackProfile.h"
 #include "M2PackRuntimeKeyProvider.h"

+#include <chrono>
 #include <cstring>

 #include <zstd.h>
@@ -40,6 +42,7 @@ bool ReadPod(const uint8_t* bytes, std::size_t size, std::size_t& offset, T& out

 bool CM2Pack::Load(const std::string& path)
 {
+	m_source_path = path;
 	std::error_code ec;
 	m_file.map(path, ec);

@@ -100,6 +103,7 @@ bool CM2Pack::Load(const std::string& path)
 bool CM2Pack::ValidateManifest()
 {
 	std::array<uint8_t, M2PACK_HASH_SIZE> manifest_hash {};
+	const auto hashStart = std::chrono::steady_clock::now();
 	crypto_generichash(
 		manifest_hash.data(),
 		manifest_hash.size(),
@@ -107,6 +111,13 @@ bool CM2Pack::ValidateManifest()
 		m_manifest_bytes.size(),
 		nullptr,
 		0);
+	RecordPackProfileStage(
+		"m2p",
+		"manifest_hash",
+		m_manifest_bytes.size(),
+		manifest_hash.size(),
+		static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+			std::chrono::steady_clock::now() - hashStart).count()));

 	if (memcmp(manifest_hash.data(), m_header.manifest_hash, manifest_hash.size()) != 0)
 	{
@@ -121,17 +132,33 @@ bool CM2Pack::ValidateManifest()
 		return false;
 	}

+	const auto verifyStart = std::chrono::steady_clock::now();
 	if (crypto_sign_verify_detached(
 		m_header.manifest_signature,
 		m_manifest_bytes.data(),
 		m_manifest_bytes.size(),
 		publicKey->data()) != 0)
 	{
+		RecordPackProfileStage(
+			"m2p",
+			"manifest_signature",
+			m_manifest_bytes.size(),
+			M2PACK_SIGNATURE_SIZE,
+			static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+				std::chrono::steady_clock::now() - verifyStart).count()));
 		TraceError("CM2Pack::ValidateManifest: manifest signature mismatch");
 		return false;
 	}
+	RecordPackProfileStage(
+		"m2p",
+		"manifest_signature",
+		m_manifest_bytes.size(),
+		M2PACK_SIGNATURE_SIZE,
+		static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+			std::chrono::steady_clock::now() - verifyStart).count()));

 	std::size_t offset = 0;
+	const auto parseStart = std::chrono::steady_clock::now();
 	TM2PackManifestHeader manifest_header {};
 	if (!ReadPod(m_manifest_bytes.data(), m_manifest_bytes.size(), offset, manifest_header))
 	{
@@ -184,6 +211,13 @@ bool CM2Pack::ValidateManifest()
 		m_index.push_back(std::move(entry));
 	}

+	RecordPackProfileStage(
+		"m2p",
+		"manifest_parse",
+		m_manifest_bytes.size(),
+		m_index.size(),
+		static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+			std::chrono::steady_clock::now() - parseStart).count()));
 	return true;
 }

@@ -196,6 +230,7 @@ bool CM2Pack::DecryptEntryPayload(const TM2PackEntry& entry, std::vector<uint8_t
 		decrypted = pPool->Acquire(entry.stored_size);
 	}
 	decrypted.resize(entry.stored_size);
+	const auto decryptStart = std::chrono::steady_clock::now();
 	unsigned long long written = 0;
 	if (crypto_aead_xchacha20poly1305_ietf_decrypt(
 		decrypted.data(),
@@ -214,6 +249,13 @@ bool CM2Pack::DecryptEntryPayload(const TM2PackEntry& entry, std::vector<uint8_t
 		}
 		return false;
 	}
+	RecordPackProfileStage(
+		"m2p",
+		"aead_decrypt",
+		entry.stored_size,
+		written,
+		static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+			std::chrono::steady_clock::now() - decryptStart).count()));

 	decrypted.resize(static_cast<std::size_t>(written));
 	return true;
@@ -243,7 +285,15 @@ bool CM2Pack::GetFileWithPool(const TM2PackEntry& entry, std::vector<uint8_t>& r
 	{
 		result.resize(entry.original_size);
 		ZSTD_DCtx* dctx = GetThreadLocalZstdContext();
+		const auto decompressStart = std::chrono::steady_clock::now();
 		size_t written = ZSTD_decompressDCtx(dctx, result.data(), result.size(), compressed.data(), compressed.size());
+		RecordPackProfileStage(
+			"m2p",
+			"zstd_decompress",
+			compressed.size(),
+			ZSTD_isError(written) ? 0 : written,
+			static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+				std::chrono::steady_clock::now() - decompressStart).count()));
 		if (pPool)
 		{
 			pPool->Release(std::move(compressed));
@@ -271,6 +321,7 @@ bool CM2Pack::GetFileWithPool(const TM2PackEntry& entry, std::vector<uint8_t>& r
 	}

 	std::array<uint8_t, M2PACK_HASH_SIZE> plain_hash {};
+	const auto hashStart = std::chrono::steady_clock::now();
 	crypto_generichash(
 		plain_hash.data(),
 		plain_hash.size(),
@@ -278,6 +329,13 @@ bool CM2Pack::GetFileWithPool(const TM2PackEntry& entry, std::vector<uint8_t>& r
 		result.size(),
 		nullptr,
 		0);
+	RecordPackProfileStage(
+		"m2p",
+		"plaintext_hash",
+		result.size(),
+		plain_hash.size(),
+		static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+			std::chrono::steady_clock::now() - hashStart).count()));

 	if (memcmp(plain_hash.data(), entry.plaintext_hash.data(), plain_hash.size()) != 0)
 	{
--- a/src/PackLib/M2Pack.h
+++ b/src/PackLib/M2Pack.h
@@ -72,6 +72,7 @@ public:

 	bool Load(const std::string& path);
 	const std::vector<TM2PackEntry>& GetIndex() const { return m_index; }
+	const std::string& GetSourcePath() const { return m_source_path; }

 	bool GetFile(const TM2PackEntry& entry, std::vector<uint8_t>& result);
 	bool GetFileWithPool(const TM2PackEntry& entry, std::vector<uint8_t>& result, CBufferPool* pPool);
@@ -82,6 +83,7 @@ private:

 private:
 	TM2PackHeader m_header {};
+	std::string m_source_path;
 	std::vector<uint8_t> m_manifest_bytes;
 	std::vector<TM2PackEntry> m_index;
 	mio::mmap_source m_file;
--- a/src/PackLib/M2PackRuntimeKeyProvider.cpp
+++ b/src/PackLib/M2PackRuntimeKeyProvider.cpp
@@ -1,4 +1,5 @@
 #include "M2PackRuntimeKeyProvider.h"
+#include "PackProfile.h"

 #include <algorithm>
 #include <cctype>
@@ -238,6 +239,8 @@ void ApplyCommandLineOption(const std::string& key, const std::string& value)

 bool InitializeM2PackRuntimeKeyProvider(const char* commandLine)
 {
+	InitializePackProfile(commandLine);
+
 	if (g_state.initialized)
 		return true;

--- a/src/PackLib/Pack.cpp
+++ b/src/PackLib/Pack.cpp
@@ -1,5 +1,8 @@
 #include "Pack.h"
+#include "PackProfile.h"
 #include "EterLib/BufferPool.h"
+
+#include <chrono>
 #include <zstd.h>

 static thread_local ZSTD_DCtx* g_zstdDCtx = nullptr;
@@ -20,6 +23,7 @@ void CPack::DecryptData(uint8_t* data, size_t len, const uint8_t* nonce)

 bool CPack::Load(const std::string& path)
 {
+	m_source_path = path;
 	std::error_code ec;
 	m_file.map(path, ec);

@@ -68,7 +72,15 @@ bool CPack::GetFileWithPool(const TPackFileEntry& entry, TPackFile& result, CBuf
 	switch (entry.encryption)
 	{
 		case 0: {
+			const auto decompressStart = std::chrono::steady_clock::now();
 			size_t decompressed_size = ZSTD_decompressDCtx(dctx, result.data(), result.size(), m_file.data() + offset, entry.compressed_size);
+			RecordPackProfileStage(
+				"pck",
+				"zstd_decompress",
+				entry.compressed_size,
+				ZSTD_isError(decompressed_size) ? 0 : decompressed_size,
+				static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+					std::chrono::steady_clock::now() - decompressStart).count()));
 			if (decompressed_size != entry.file_size) {
 				return false;
 			}
@@ -83,9 +95,25 @@ bool CPack::GetFileWithPool(const TPackFileEntry& entry, TPackFile& result, CBuf

 			memcpy(compressed_data.data(), m_file.data() + offset, entry.compressed_size);

+			const auto decryptStart = std::chrono::steady_clock::now();
 			DecryptData(compressed_data.data(), entry.compressed_size, entry.nonce);
+			RecordPackProfileStage(
+				"pck",
+				"xchacha20_decrypt",
+				entry.compressed_size,
+				entry.compressed_size,
+				static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+					std::chrono::steady_clock::now() - decryptStart).count()));

+			const auto decompressStart = std::chrono::steady_clock::now();
 			size_t decompressed_size = ZSTD_decompressDCtx(dctx, result.data(), result.size(), compressed_data.data(), compressed_data.size());
+			RecordPackProfileStage(
+				"pck",
+				"zstd_decompress",
+				compressed_data.size(),
+				ZSTD_isError(decompressed_size) ? 0 : decompressed_size,
+				static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+					std::chrono::steady_clock::now() - decompressStart).count()));

 			if (pPool) {
 				pPool->Release(std::move(compressed_data));
--- a/src/PackLib/Pack.h
+++ b/src/PackLib/Pack.h
@@ -14,6 +14,7 @@ public:

 	bool Load(const std::string& path);
 	const std::vector<TPackFileEntry>& GetIndex() const { return m_index; }
+	const std::string& GetSourcePath() const { return m_source_path; }

 	bool GetFile(const TPackFileEntry& entry, TPackFile& result);
 	bool GetFileWithPool(const TPackFileEntry& entry, TPackFile& result, CBufferPool* pPool);
@@ -22,6 +23,7 @@ private:
 	void DecryptData(uint8_t* data, size_t len, const uint8_t* nonce);

 	TPackFileHeader m_header;
+	std::string m_source_path;
 	std::vector<TPackFileEntry> m_index;
 	mio::mmap_source m_file;
 };
--- a/src/PackLib/PackManager.cpp
+++ b/src/PackLib/PackManager.cpp
@@ -1,5 +1,8 @@
 #include "PackManager.h"
+#include "PackProfile.h"
 #include "EterLib/BufferPool.h"
+
+#include <chrono>
 #include <filesystem>
 #include <fstream>
 #include <memory>
@@ -27,8 +30,16 @@ bool CPackManager::AddPack(const std::string& path)
 	if (packPath.extension() == ".m2p")
 	{
 		std::shared_ptr<CM2Pack> pack = std::make_shared<CM2Pack>();
+		const auto loadStart = std::chrono::steady_clock::now();
 		if (!pack->Load(path))
 		{
+			RecordPackProfileMount(
+				"m2p",
+				path,
+				false,
+				0,
+				static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+					std::chrono::steady_clock::now() - loadStart).count()));
 			return false;
 		}

@@ -38,14 +49,29 @@ bool CPackManager::AddPack(const std::string& path)
 		{
 			m_m2_entries[entry.path] = std::make_pair(pack, entry);
 		}
+		RecordPackProfileMount(
+			"m2p",
+			path,
+			true,
+			index.size(),
+			static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+				std::chrono::steady_clock::now() - loadStart).count()));

 		return true;
 	}

 	std::shared_ptr<CPack> pack = std::make_shared<CPack>();
+	const auto loadStart = std::chrono::steady_clock::now();

 	if (!pack->Load(path))
 	{
+		RecordPackProfileMount(
+			"pck",
+			path,
+			false,
+			0,
+			static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+				std::chrono::steady_clock::now() - loadStart).count()));
 		return false;
 	}

@@ -55,6 +81,13 @@ bool CPackManager::AddPack(const std::string& path)
 	{
 		m_entries[entry.file_name] = std::make_pair(pack, entry);
 	}
+	RecordPackProfileMount(
+		"pck",
+		path,
+		true,
+		index.size(),
+		static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+			std::chrono::steady_clock::now() - loadStart).count()));

 	return true;
 }
@@ -73,16 +106,37 @@ bool CPackManager::GetFileWithPool(std::string_view path, TPackFile& result, CBu
 	if (m_load_from_pack) {
 		auto m2it = m_m2_entries.find(buf);
 		if (m2it != m_m2_entries.end()) {
-			return m2it->second.first->GetFileWithPool(m2it->second.second, result, pPool);
+			const auto loadStart = std::chrono::steady_clock::now();
+			const bool ok = m2it->second.first->GetFileWithPool(m2it->second.second, result, pPool);
+			RecordPackProfileLoad(
+				"m2p",
+				m2it->second.first->GetSourcePath(),
+				buf,
+				ok,
+				ok ? result.size() : 0,
+				static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+					std::chrono::steady_clock::now() - loadStart).count()));
+			return ok;
 		}

 		auto it = m_entries.find(buf);
 		if (it != m_entries.end()) {
-			return it->second.first->GetFileWithPool(it->second.second, result, pPool);
+			const auto loadStart = std::chrono::steady_clock::now();
+			const bool ok = it->second.first->GetFileWithPool(it->second.second, result, pPool);
+			RecordPackProfileLoad(
+				"pck",
+				it->second.first->GetSourcePath(),
+				buf,
+				ok,
+				ok ? result.size() : 0,
+				static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+					std::chrono::steady_clock::now() - loadStart).count()));
+			return ok;
 		}
 	}

 	// Fallback to disk (for files not in packs, like bgm folder)
+	const auto loadStart = std::chrono::steady_clock::now();
 	std::ifstream ifs(buf, std::ios::binary);
 	if (ifs.is_open()) {
 		ifs.seekg(0, std::ios::end);
@@ -97,10 +151,27 @@ bool CPackManager::GetFileWithPool(std::string_view path, TPackFile& result, CBu
 		}

 		if (ifs.read((char*)result.data(), size)) {
+			RecordPackProfileLoad(
+				"disk",
+				"<disk>",
+				buf,
+				true,
+				result.size(),
+				static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+					std::chrono::steady_clock::now() - loadStart).count()));
 			return true;
 		}
 	}

+	RecordPackProfileLoad(
+		"disk",
+		"<disk>",
+		buf,
+		false,
+		0,
+		static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+			std::chrono::steady_clock::now() - loadStart).count()));
+
 	return false;
 }

--- a/src/PackLib/PackProfile.cpp
+++ b/src/PackLib/PackProfile.cpp
@@ -0,0 +1,494 @@
+#include "PackProfile.h"
+
+#include <algorithm>
+#include <array>
+#include <cctype>
+#include <chrono>
+#include <filesystem>
+#include <fstream>
+#include <map>
+#include <mutex>
+#include <sstream>
+#include <string>
+#include <vector>
+
+#include <windows.h>
+
+#include "EterBase/Utils.h"
+
+namespace
+{
+
+using Clock = std::chrono::steady_clock;
+
+constexpr const char* kPackProfileEnv = "M2PACK_PROFILE";
+constexpr const char* kPackProfileOutput = "log/pack_profile.txt";
+constexpr std::size_t kTopListLimit = 12;
+
+struct LoadStats
+{
+	std::uint64_t count = 0;
+	std::uint64_t failures = 0;
+	std::uint64_t output_bytes = 0;
+	std::uint64_t elapsed_us = 0;
+};
+
+struct MountStats
+{
+	std::uint64_t count = 0;
+	std::uint64_t failures = 0;
+	std::uint64_t entry_count = 0;
+	std::uint64_t elapsed_us = 0;
+};
+
+struct StageStats
+{
+	std::uint64_t count = 0;
+	std::uint64_t input_bytes = 0;
+	std::uint64_t output_bytes = 0;
+	std::uint64_t elapsed_us = 0;
+};
+
+struct PhaseMarker
+{
+	std::string phase;
+	std::uint64_t elapsed_us = 0;
+};
+
+struct PackProfileState
+{
+	bool initialized = false;
+	bool enabled = false;
+	std::string current_phase = "startup";
+	Clock::time_point start_time {};
+	std::vector<PhaseMarker> markers;
+	std::map<std::string, LoadStats> load_by_format;
+	std::map<std::string, LoadStats> load_by_phase_format;
+	std::map<std::string, LoadStats> load_by_phase_pack;
+	std::map<std::string, LoadStats> load_by_extension;
+	std::map<std::string, MountStats> mount_by_format;
+	std::map<std::string, MountStats> mount_by_pack;
+	std::map<std::string, StageStats> stage_by_key;
+	std::mutex mutex;
+
+	~PackProfileState()
+	{
+		if (enabled)
+		{
+			std::lock_guard<std::mutex> lock(mutex);
+			WriteReportLocked("shutdown");
+		}
+	}
+
+	void WriteReportLocked(std::string_view reason) const
+	{
+		std::error_code ec;
+		std::filesystem::create_directories("log", ec);
+
+		std::ofstream output(kPackProfileOutput, std::ios::binary | std::ios::trunc);
+		if (!output)
+		{
+			return;
+		}
+
+		output << "PACK PROFILE REPORT\n";
+		output << "reason=" << reason << "\n";
+		output << "current_phase=" << current_phase << "\n";
+
+		const auto uptime_us = start_time == Clock::time_point {}
+			? 0
+			: static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+				Clock::now() - start_time).count());
+		output << "uptime_ms=" << FormatMs(uptime_us) << "\n\n";
+
+		output << "[phase_markers]\n";
+		for (const auto& marker : markers)
+		{
+			output << marker.phase << "\t" << FormatMs(marker.elapsed_us) << " ms\n";
+		}
+		output << "\n";
+
+		WriteMountSection(output, "[mounts_by_format]", mount_by_format);
+		WriteMountSection(output, "[mounts_by_pack]", mount_by_pack, kTopListLimit);
+		WriteLoadSection(output, "[loads_by_format]", load_by_format);
+		WriteLoadSection(output, "[loads_by_phase_format]", load_by_phase_format);
+		WriteLoadSection(output, "[top_phase_pack_loads]", load_by_phase_pack, kTopListLimit);
+		WriteLoadSection(output, "[top_extension_loads]", load_by_extension, kTopListLimit);
+		WriteStageSection(output, "[loader_stages]", stage_by_key);
+	}
+
+	static std::string FormatMs(std::uint64_t elapsed_us)
+	{
+		std::ostringstream out;
+		out.setf(std::ios::fixed, std::ios::floatfield);
+		out.precision(3);
+		out << (static_cast<double>(elapsed_us) / 1000.0);
+		return out.str();
+	}
+
+	static std::string ToLowerAscii(std::string value)
+	{
+		std::transform(value.begin(), value.end(), value.begin(), [](unsigned char ch) {
+			return static_cast<char>(std::tolower(ch));
+		});
+		return value;
+	}
+
+	static std::string ParsePackLabel(std::string_view pack_path)
+	{
+		const std::filesystem::path path { std::string(pack_path) };
+		const auto filename = path.filename().string();
+		if (!filename.empty())
+		{
+			return ToLowerAscii(filename);
+		}
+
+		return ToLowerAscii(std::string(pack_path));
+	}
+
+	static std::string ParseExtension(std::string_view request_path)
+	{
+		const std::filesystem::path path { std::string(request_path) };
+		auto extension = path.extension().string();
+		if (extension.empty())
+		{
+			return "<none>";
+		}
+
+		return ToLowerAscii(std::move(extension));
+	}
+
+	static std::string MakePhaseKey(std::string_view phase, std::string_view suffix)
+	{
+		std::string key;
+		key.reserve(phase.size() + suffix.size() + 3);
+		key.append(phase);
+		key.append(" | ");
+		key.append(suffix);
+		return key;
+	}
+
+	template <typename MapType>
+	static std::vector<std::pair<std::string, typename MapType::mapped_type>> SortByTimeDesc(const MapType& values)
+	{
+		using StatsType = typename MapType::mapped_type;
+		std::vector<std::pair<std::string, StatsType>> sorted;
+		sorted.reserve(values.size());
+		for (const auto& [key, stats] : values)
+		{
+			sorted.emplace_back(key, stats);
+		}
+		std::sort(sorted.begin(), sorted.end(), [](const auto& left, const auto& right) {
+			if (left.second.elapsed_us != right.second.elapsed_us)
+			{
+				return left.second.elapsed_us > right.second.elapsed_us;
+			}
+
+			return left.first < right.first;
+		});
+		return sorted;
+	}
+
+	static void WriteLoadSection(std::ofstream& output, std::string_view header, const std::map<std::string, LoadStats>& values, std::size_t limit = 0)
+	{
+		output << header << "\n";
+		const auto sorted = SortByTimeDesc(values);
+		const std::size_t count = limit == 0 ? sorted.size() : std::min(limit, sorted.size());
+		for (std::size_t i = 0; i < count; ++i)
+		{
+			const auto& [key, stats] = sorted[i];
+			output
+				<< key
+				<< "\tcount=" << stats.count
+				<< "\tfail=" << stats.failures
+				<< "\tbytes=" << stats.output_bytes
+				<< "\ttime_ms=" << FormatMs(stats.elapsed_us)
+				<< "\n";
+		}
+		output << "\n";
+	}
+
+	static void WriteMountSection(std::ofstream& output, std::string_view header, const std::map<std::string, MountStats>& values, std::size_t limit = 0)
+	{
+		output << header << "\n";
+		std::vector<std::pair<std::string, MountStats>> sorted(values.begin(), values.end());
+		std::sort(sorted.begin(), sorted.end(), [](const auto& left, const auto& right) {
+			if (left.second.elapsed_us != right.second.elapsed_us)
+			{
+				return left.second.elapsed_us > right.second.elapsed_us;
+			}
+
+			return left.first < right.first;
+		});
+
+		const std::size_t count = limit == 0 ? sorted.size() : std::min(limit, sorted.size());
+		for (std::size_t i = 0; i < count; ++i)
+		{
+			const auto& [key, stats] = sorted[i];
+			output
+				<< key
+				<< "\tcount=" << stats.count
+				<< "\tfail=" << stats.failures
+				<< "\tentries=" << stats.entry_count
+				<< "\ttime_ms=" << FormatMs(stats.elapsed_us)
+				<< "\n";
+		}
+		output << "\n";
+	}
+
+	static void WriteStageSection(std::ofstream& output, std::string_view header, const std::map<std::string, StageStats>& values)
+	{
+		output << header << "\n";
+		std::vector<std::pair<std::string, StageStats>> sorted(values.begin(), values.end());
+		std::sort(sorted.begin(), sorted.end(), [](const auto& left, const auto& right) {
+			if (left.second.elapsed_us != right.second.elapsed_us)
+			{
+				return left.second.elapsed_us > right.second.elapsed_us;
+			}
+
+			return left.first < right.first;
+		});
+
+		for (const auto& [key, stats] : sorted)
+		{
+			output
+				<< key
+				<< "\tcount=" << stats.count
+				<< "\tin=" << stats.input_bytes
+				<< "\tout=" << stats.output_bytes
+				<< "\ttime_ms=" << FormatMs(stats.elapsed_us)
+				<< "\n";
+		}
+		output << "\n";
+	}
+};
+
+PackProfileState g_pack_profile;
+
+bool ParseBoolFlag(std::string value, bool& out)
+{
+	value.erase(std::remove_if(value.begin(), value.end(), [](unsigned char ch) {
+		return std::isspace(ch) != 0;
+	}), value.end());
+
+	std::transform(value.begin(), value.end(), value.begin(), [](unsigned char ch) {
+		return static_cast<char>(std::tolower(ch));
+	});
+
+	if (value == "1" || value == "true" || value == "yes" || value == "on")
+	{
+		out = true;
+		return true;
+	}
+
+	if (value == "0" || value == "false" || value == "no" || value == "off")
+	{
+		out = false;
+		return true;
+	}
+
+	return false;
+}
+
+std::string GetEnvString(const char* name)
+{
+	char buffer[256];
+	const DWORD len = GetEnvironmentVariableA(name, buffer, sizeof(buffer));
+	if (len == 0 || len >= sizeof(buffer))
+	{
+		return {};
+	}
+
+	return std::string(buffer, buffer + len);
+}
+
+std::uint64_t CurrentElapsedUs()
+{
+	if (!g_pack_profile.enabled)
+	{
+		return 0;
+	}
+
+	return static_cast<std::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
+		Clock::now() - g_pack_profile.start_time).count());
+}
+
+} // namespace
+
+void InitializePackProfile(const char* commandLine)
+{
+	if (g_pack_profile.initialized)
+	{
+		return;
+	}
+
+	g_pack_profile.initialized = true;
+	g_pack_profile.enabled = false;
+
+	const std::string envProfile = GetEnvString(kPackProfileEnv);
+	if (!envProfile.empty())
+	{
+		bool enabled = false;
+		if (ParseBoolFlag(envProfile, enabled))
+		{
+			g_pack_profile.enabled = enabled;
+		}
+	}
+
+	int argc = 0;
+	PCHAR* argv = CommandLineToArgv(const_cast<PCHAR>(commandLine ? commandLine : ""), &argc);
+	if (argv)
+	{
+		for (int i = 0; i < argc; ++i)
+		{
+			const std::string arg = argv[i];
+			if (arg != "--m2pack-profile")
+			{
+				continue;
+			}
+
+			bool enabled = true;
+			if (i + 1 < argc)
+			{
+				const std::string next = argv[i + 1];
+				if (!next.starts_with("--") && ParseBoolFlag(next, enabled))
+				{
+					++i;
+				}
+			}
+
+			g_pack_profile.enabled = enabled;
+		}
+
+		SAFE_FREE_GLOBAL(argv);
+	}
+
+	if (!g_pack_profile.enabled)
+	{
+		return;
+	}
+
+	std::lock_guard<std::mutex> lock(g_pack_profile.mutex);
+	g_pack_profile.current_phase = "startup";
+	g_pack_profile.start_time = Clock::now();
+	g_pack_profile.markers.push_back(PhaseMarker {
+		.phase = g_pack_profile.current_phase,
+		.elapsed_us = 0,
+	});
+	g_pack_profile.WriteReportLocked("initialized");
+}
+
+bool IsPackProfileEnabled()
+{
+	return g_pack_profile.enabled;
+}
+
+void MarkPackProfilePhase(std::string_view phase)
+{
+	if (!g_pack_profile.enabled)
+	{
+		return;
+	}
+
+	std::lock_guard<std::mutex> lock(g_pack_profile.mutex);
+	if (g_pack_profile.current_phase == phase)
+	{
+		return;
+	}
+
+	g_pack_profile.current_phase = std::string(phase);
+	g_pack_profile.markers.push_back(PhaseMarker {
+		.phase = g_pack_profile.current_phase,
+		.elapsed_us = CurrentElapsedUs(),
+	});
+	g_pack_profile.WriteReportLocked(PackProfileState::MakePhaseKey("phase", phase));
+}
+
+void RecordPackProfileMount(
+	std::string_view format,
+	std::string_view packPath,
+	bool ok,
+	std::size_t entryCount,
+	std::uint64_t elapsedUs)
+{
+	if (!g_pack_profile.enabled)
+	{
+		return;
+	}
+
+	std::lock_guard<std::mutex> lock(g_pack_profile.mutex);
+
+	auto& formatStats = g_pack_profile.mount_by_format[std::string(format)];
+	formatStats.count += 1;
+	formatStats.failures += ok ? 0 : 1;
+	formatStats.entry_count += entryCount;
+	formatStats.elapsed_us += elapsedUs;
+
+	auto& packStats = g_pack_profile.mount_by_pack[PackProfileState::ParsePackLabel(packPath)];
+	packStats.count += 1;
+	packStats.failures += ok ? 0 : 1;
+	packStats.entry_count += entryCount;
+	packStats.elapsed_us += elapsedUs;
+}
+
+void RecordPackProfileLoad(
+	std::string_view format,
+	std::string_view packPath,
+	std::string_view requestPath,
+	bool ok,
+	std::uint64_t outputBytes,
+	std::uint64_t elapsedUs)
+{
+	if (!g_pack_profile.enabled)
+	{
+		return;
+	}
+
+	std::lock_guard<std::mutex> lock(g_pack_profile.mutex);
+
+	auto update = [ok, outputBytes, elapsedUs](LoadStats& stats) {
+		stats.count += 1;
+		stats.failures += ok ? 0 : 1;
+		stats.output_bytes += outputBytes;
+		stats.elapsed_us += elapsedUs;
+	};
+
+	update(g_pack_profile.load_by_format[std::string(format)]);
+	update(g_pack_profile.load_by_phase_format[
+		PackProfileState::MakePhaseKey(g_pack_profile.current_phase, format)]);
+	update(g_pack_profile.load_by_phase_pack[
+		PackProfileState::MakePhaseKey(g_pack_profile.current_phase, PackProfileState::ParsePackLabel(packPath))]);
+	update(g_pack_profile.load_by_extension[PackProfileState::ParseExtension(requestPath)]);
+}
+
+void RecordPackProfileStage(
+	std::string_view format,
+	std::string_view stage,
+	std::uint64_t inputBytes,
+	std::uint64_t outputBytes,
+	std::uint64_t elapsedUs)
+{
+	if (!g_pack_profile.enabled)
+	{
+		return;
+	}
+
+	std::lock_guard<std::mutex> lock(g_pack_profile.mutex);
+	auto& stats = g_pack_profile.stage_by_key[
+		PackProfileState::MakePhaseKey(format, stage)];
+	stats.count += 1;
+	stats.input_bytes += inputBytes;
+	stats.output_bytes += outputBytes;
+	stats.elapsed_us += elapsedUs;
+}
+
+void FlushPackProfileSnapshot(std::string_view reason)
+{
+	if (!g_pack_profile.enabled)
+	{
+		return;
+	}
+
+	std::lock_guard<std::mutex> lock(g_pack_profile.mutex);
+	g_pack_profile.WriteReportLocked(reason);
+}
--- a/src/PackLib/PackProfile.h
+++ b/src/PackLib/PackProfile.h
@@ -0,0 +1,29 @@
+#pragma once
+
+#include <cstddef>
+#include <cstdint>
+#include <string_view>
+
+void InitializePackProfile(const char* commandLine);
+bool IsPackProfileEnabled();
+void MarkPackProfilePhase(std::string_view phase);
+void RecordPackProfileMount(
+	std::string_view format,
+	std::string_view packPath,
+	bool ok,
+	std::size_t entryCount,
+	std::uint64_t elapsedUs);
+void RecordPackProfileLoad(
+	std::string_view format,
+	std::string_view packPath,
+	std::string_view requestPath,
+	bool ok,
+	std::uint64_t outputBytes,
+	std::uint64_t elapsedUs);
+void RecordPackProfileStage(
+	std::string_view format,
+	std::string_view stage,
+	std::uint64_t inputBytes,
+	std::uint64_t outputBytes,
+	std::uint64_t elapsedUs);
+void FlushPackProfileSnapshot(std::string_view reason);
--- a/src/UserInterface/PythonNetworkStreamPhaseGame.cpp
+++ b/src/UserInterface/PythonNetworkStreamPhaseGame.cpp
@@ -20,6 +20,7 @@
 #include "PythonApplication.h"

 #include "GameLib/ItemManager.h"
+#include "PackLib/PackProfile.h"

 #include "AbstractApplication.h"
 #include "AbstractCharacterManager.h"
@@ -414,6 +415,7 @@ void CPythonNetworkStream::SetGamePhase()
 	if ("Game"!=m_strPhase)
 		m_phaseLeaveFunc.Run();

+	MarkPackProfilePhase("game");
 	m_strPhase = "Game";

 	m_dwChangingPhaseTime = ELTimer_GetMSec();
--- a/src/UserInterface/PythonNetworkStreamPhaseLoading.cpp
+++ b/src/UserInterface/PythonNetworkStreamPhaseLoading.cpp
@@ -5,6 +5,7 @@
 #include "NetworkActorManager.h"
 #include "AbstractPlayer.h"
 #include "PackLib/PackManager.h"
+#include "PackLib/PackProfile.h"

 void CPythonNetworkStream::EnableChatInsultFilter(bool isEnable)
 {
@@ -90,6 +91,7 @@ void CPythonNetworkStream::SetLoadingPhase()
 	Tracen("");
 	Tracen("## Network - Loading Phase ##");
 	Tracen("");
+	MarkPackProfilePhase("loading");

 	m_strPhase = "Loading";

--- a/src/UserInterface/PythonNetworkStreamPhaseLogin.cpp
+++ b/src/UserInterface/PythonNetworkStreamPhaseLogin.cpp
@@ -2,6 +2,7 @@
 #include "PythonNetworkStream.h"
 #include "Packet.h"
 #include "AccountConnector.h"
+#include "PackLib/PackProfile.h"

 // Login ---------------------------------------------------------------------------
 void CPythonNetworkStream::LoginPhase()
@@ -18,6 +19,7 @@ void CPythonNetworkStream::SetLoginPhase()
 	Tracen("");
 	Tracen("## Network - Login Phase ##");
 	Tracen("");
+	MarkPackProfilePhase("login");

 	m_strPhase = "Login";