add more trace scopes (#362)

* more trace scopes
* Make sure ReplayLogEntries uses the correct size for oplog buffer
* changelog

14 files changed, 438 insertions, 282 deletions

diff --git a/src/zencore/iobuffer.cpp b/src/zencore/iobuffer.cpp
index 73600a09e..09cd0a000 100644
--- a/src/zencore/iobuffer.cpp
+++ b/src/zencore/iobuffer.cpp
@@ -10,6 +10,7 @@
 #include <zencore/memory.h>
 #include <zencore/testing.h>
 #include <zencore/thread.h>
+#include <zencore/trace.h>
 
 #include <memory.h>
 #include <system_error>
@@ -154,6 +155,7 @@ IoBufferCore::MakeOwned(bool Immutable)
 {
 	if (!IsOwned())
 	{
+		ZEN_TRACE_CPU("IoBufferCore::MakeOwned");
 		const void* OldDataPtr = m_DataPtr;
 		AllocateBuffer(m_DataBytes, sizeof(void*));
 		memcpy(const_cast<void*>(m_DataPtr), OldDataPtr, m_DataBytes);
@@ -275,6 +277,8 @@ IoBufferExtendedCore::Materialize() const
 	if (m_Flags.load(std::memory_order_acquire) & kIsMaterialized)
 		return;
 
+	ZEN_TRACE_CPU("IoBufferExtendedCore::Materialize");
+
 	RwLock::ExclusiveLockScope _(MappingLockForInstance(this));
 
 	// Someone could have gotten here first
@@ -296,6 +300,8 @@ IoBufferExtendedCore::Materialize() const
 
 	if (m_DataBytes < DisableMMapSizeLimit)
 	{
+		ZEN_TRACE_CPU("IoBufferExtendedCore::Materialize::Read");
+
 		AllocateBuffer(m_DataBytes, sizeof(void*));
 		NewFlags |= kIsOwnedByThis;
 		int32_t Error	  = 0;
@@ -351,6 +357,8 @@ IoBufferExtendedCore::Materialize() const
 		return;
 	}
 
+	ZEN_TRACE_CPU("IoBufferExtendedCore::Materialize::MMap");
+
 	void* NewMmapHandle;
 
 	const uint64_t MapOffset				= m_FileOffset & ~0xffffull;
@@ -572,12 +580,16 @@ IoBufferBuilder::ReadFromFileMaybe(IoBuffer& InBuffer)
 IoBuffer
 IoBufferBuilder::MakeFromFileHandle(void* FileHandle, uint64_t Offset, uint64_t Size)
 {
+	ZEN_TRACE_CPU("IoBufferBuilder::MakeFromFileHandle");
+
 	return IoBuffer(IoBuffer::BorrowedFile, FileHandle, Offset, Size);
 }
 
 IoBuffer
 IoBufferBuilder::MakeFromFile(const std::filesystem::path& FileName, uint64_t Offset, uint64_t Size)
 {
+	ZEN_TRACE_CPU("IoBufferBuilder::MakeFromFile");
+
 	uint64_t FileSize;
 
 #if ZEN_PLATFORM_WINDOWS
@@ -640,6 +652,8 @@ IoBufferBuilder::MakeFromFile(const std::filesystem::path& FileName, uint64_t Of
 IoBuffer
 IoBufferBuilder::MakeFromTemporaryFile(const std::filesystem::path& FileName)
 {
+	ZEN_TRACE_CPU("IoBufferBuilder::MakeFromTemporaryFile");
+
 	uint64_t FileSize;
 	void*	 Handle;
 
diff --git a/src/zenhttp/httpasio.cpp b/src/zenhttp/httpasio.cpp
index 4d1f35c2b..affe328e3 100644
--- a/src/zenhttp/httpasio.cpp
+++ b/src/zenhttp/httpasio.cpp
@@ -216,6 +216,8 @@ public:
 
 	void InitializeForPayload(uint16_t ResponseCode, std::span<IoBuffer> BlobList)
 	{
+		ZEN_TRACE_CPU("asio::InitializeForPayload");
+
 		m_ResponseCode			  = ResponseCode;
 		const uint32_t ChunkCount = gsl::narrow<uint32_t>(BlobList.size());
 
@@ -578,13 +580,15 @@ HttpServerConnection::HandleRequest()
 
 			// TODO: should cork/uncork for Linux?
 
-			asio::async_write(*m_Socket.get(),
-							  ResponseBuffers,
-							  asio::transfer_exactly(ResponseLength),
-							  [Conn = AsSharedPtr()](const asio::error_code& Ec, std::size_t ByteCount) {
-								  Conn->OnResponseDataSent(Ec, ByteCount, true);
-							  });
-
+			{
+				ZEN_TRACE_CPU("asio::async_write");
+				asio::async_write(*m_Socket.get(),
+								  ResponseBuffers,
+								  asio::transfer_exactly(ResponseLength),
+								  [Conn = AsSharedPtr()](const asio::error_code& Ec, std::size_t ByteCount) {
+									  Conn->OnResponseDataSent(Ec, ByteCount, true);
+								  });
+			}
 			return;
 		}
 	}
diff --git a/src/zenhttp/httpsys.cpp b/src/zenhttp/httpsys.cpp
index 342fdd047..3bcaa5861 100644
--- a/src/zenhttp/httpsys.cpp
+++ b/src/zenhttp/httpsys.cpp
@@ -351,6 +351,8 @@ HttpMessageResponseRequest::~HttpMessageResponseRequest()
 void
 HttpMessageResponseRequest::InitializeForPayload(uint16_t ResponseCode, std::span<IoBuffer> BlobList)
 {
+	ZEN_TRACE_CPU("httpsys::InitializeForPayload");
+
 	const uint32_t ChunkCount = gsl::narrow<uint32_t>(BlobList.size());
 
 	m_HttpDataChunks.reserve(ChunkCount);
@@ -459,6 +461,7 @@ HttpMessageResponseRequest::HandleCompletion(ULONG IoResult, ULONG_PTR NumberOfB
 void
 HttpMessageResponseRequest::IssueRequest(std::error_code& ErrorCode)
 {
+	ZEN_TRACE_CPU("httpsys::Response::IssueRequest");
 	HttpSysTransaction& Tx		= Transaction();
 	HTTP_REQUEST* const HttpReq = Tx.HttpRequest();
 	PTP_IO const		Iocp	= Tx.Iocp();
@@ -663,6 +666,7 @@ HttpAsyncWorkRequest::~HttpAsyncWorkRequest()
 void
 HttpAsyncWorkRequest::IssueRequest(std::error_code& ErrorCode)
 {
+	ZEN_TRACE_CPU("httpsys::AsyncWork::IssueRequest");
 	ErrorCode.clear();
 
 	Transaction().Server().WorkPool().ScheduleWork(m_WorkItem);
@@ -697,7 +701,10 @@ HttpAsyncWorkRequest::AsyncWorkItem::Execute()
 
 		ThisRequest.m_NextCompletionHandler = nullptr;
 
-		Handler(ThisRequest);
+		{
+			ZEN_TRACE_CPU("httpsys::HandleRequest");
+			Handler(ThisRequest);
+		}
 
 		// TODO: should Handler be destroyed at this point to ensure there
 		//		 are no outstanding references into state which could be
@@ -1152,6 +1159,8 @@ HttpSysTransaction::IoCompletionCallback(PTP_CALLBACK_INSTANCE Instance,
 bool
 HttpSysTransaction::IssueNextRequest(HttpSysRequestHandler* NewCompletionHandler)
 {
+	ZEN_TRACE_CPU("httpsys::Transaction::IssueNextRequest");
+
 	HttpSysRequestHandler* CurrentHandler = m_CompletionHandler;
 	m_CompletionHandler					  = NewCompletionHandler;
 
@@ -1479,6 +1488,8 @@ InitialRequestHandler::~InitialRequestHandler()
 void
 InitialRequestHandler::IssueRequest(std::error_code& ErrorCode)
 {
+	ZEN_TRACE_CPU("httpsys::Request::IssueRequest");
+
 	HttpSysTransaction& Tx		= Transaction();
 	PTP_IO				Iocp	= Tx.Iocp();
 	HTTP_REQUEST*		HttpReq = Tx.HttpRequest();
diff --git a/src/zenserver/cache/cachedisklayer.cpp b/src/zenserver/cache/cachedisklayer.cpp
index 9d3935131..7adf07350 100644
--- a/src/zenserver/cache/cachedisklayer.cpp
+++ b/src/zenserver/cache/cachedisklayer.cpp
@@ -183,7 +183,7 @@ ZenCacheDiskLayer::CacheBucket::OpenOrCreate(std::filesystem::path BucketDir, bo
 {
 	using namespace std::literals;
 
-	ZEN_TRACE_CPU("Z$::Bucket::OpenOrCreate");
+	ZEN_TRACE_CPU("Z$::Disk::Bucket::OpenOrCreate");
 
 	ZEN_LOG_SCOPE("opening cache bucket '{}'", BucketDir);
 
@@ -232,6 +232,8 @@ ZenCacheDiskLayer::CacheBucket::OpenOrCreate(std::filesystem::path BucketDir, bo
 
 	if (!IsNew)
 	{
+		ZEN_TRACE_CPU("Z$::Disk::Bucket::OpenOrCreate::Manifest");
+
 		Stopwatch  Timer;
 		const auto _ =
 			MakeGuard([&] { ZEN_INFO("read store manifest '{}' in {}", ManifestPath, NiceTimeSpanMs(Timer.GetElapsedTimeMs())); });
@@ -277,7 +279,7 @@ ZenCacheDiskLayer::CacheBucket::OpenOrCreate(std::filesystem::path BucketDir, bo
 void
 ZenCacheDiskLayer::CacheBucket::MakeIndexSnapshot()
 {
-	ZEN_TRACE_CPU("Z$::Bucket::MakeIndexSnapshot");
+	ZEN_TRACE_CPU("Z$::Disk::Bucket::MakeIndexSnapshot");
 
 	uint64_t LogCount = m_SlogFile.GetLogCount();
 	if (m_LogFlushPosition == LogCount)
@@ -362,7 +364,7 @@ ZenCacheDiskLayer::CacheBucket::MakeIndexSnapshot()
 uint64_t
 ZenCacheDiskLayer::CacheBucket::ReadIndexFile(const std::filesystem::path& IndexPath, uint32_t& OutVersion)
 {
-	ZEN_TRACE_CPU("Z$::Bucket::ReadIndexFile");
+	ZEN_TRACE_CPU("Z$::Disk::Bucket::ReadIndexFile");
 
 	if (std::filesystem::is_regular_file(IndexPath))
 	{
@@ -437,7 +439,7 @@ ZenCacheDiskLayer::CacheBucket::ReadIndexFile(const std::filesystem::path& Index
 uint64_t
 ZenCacheDiskLayer::CacheBucket::ReadLog(const std::filesystem::path& LogPath, uint64_t SkipEntryCount)
 {
-	ZEN_TRACE_CPU("Z$::Bucket::ReadLog");
+	ZEN_TRACE_CPU("Z$::Disk::Bucket::ReadLog");
 
 	if (std::filesystem::is_regular_file(LogPath))
 	{
@@ -492,7 +494,7 @@ ZenCacheDiskLayer::CacheBucket::ReadLog(const std::filesystem::path& LogPath, ui
 void
 ZenCacheDiskLayer::CacheBucket::OpenLog(const bool IsNew)
 {
-	ZEN_TRACE_CPU("Z$::Bucket::OpenLog");
+	ZEN_TRACE_CPU("Z$::Disk::Bucket::OpenLog");
 
 	m_TotalStandaloneSize = 0;
 
@@ -624,6 +626,8 @@ ZenCacheDiskLayer::CacheBucket::BuildPath(PathBuilderBase& Path, const IoHash& H
 IoBuffer
 ZenCacheDiskLayer::CacheBucket::GetInlineCacheValue(const DiskLocation& Loc) const
 {
+	ZEN_TRACE_CPU("Z$::Disk::Bucket::GetInlineCacheValue");
+
 	BlockStoreLocation Location = Loc.GetBlockLocation(m_PayloadAlignment);
 
 	IoBuffer Value = m_BlockStore.TryGetChunk(Location);
@@ -638,7 +642,7 @@ ZenCacheDiskLayer::CacheBucket::GetInlineCacheValue(const DiskLocation& Loc) con
 IoBuffer
 ZenCacheDiskLayer::CacheBucket::GetStandaloneCacheValue(const DiskLocation& Loc, const IoHash& HashKey) const
 {
-	ZEN_TRACE_CPU("Z$::Bucket::GetStandaloneCacheValue");
+	ZEN_TRACE_CPU("Z$::Disk::Bucket::GetStandaloneCacheValue");
 
 	ExtendablePathBuilder<256> DataFilePath;
 	BuildPath(DataFilePath, HashKey);
@@ -723,7 +727,7 @@ ZenCacheDiskLayer::CacheBucket::Put(const IoHash& HashKey, const ZenCacheValue&
 bool
 ZenCacheDiskLayer::CacheBucket::Drop()
 {
-	ZEN_TRACE_CPU("Z$::Bucket::Drop");
+	ZEN_TRACE_CPU("Z$::Disk::Bucket::Drop");
 
 	RwLock::ExclusiveLockScope _(m_IndexLock);
 
@@ -747,7 +751,7 @@ ZenCacheDiskLayer::CacheBucket::Drop()
 void
 ZenCacheDiskLayer::CacheBucket::Flush()
 {
-	ZEN_TRACE_CPU("Z$::Bucket::Flush");
+	ZEN_TRACE_CPU("Z$::Disk::Bucket::Flush");
 
 	m_BlockStore.Flush();
 
@@ -762,7 +766,7 @@ ZenCacheDiskLayer::CacheBucket::SaveManifest()
 {
 	using namespace std::literals;
 
-	ZEN_TRACE_CPU("Z$::Bucket::SaveManifest");
+	ZEN_TRACE_CPU("Z$::Disk::Bucket::SaveManifest");
 
 	CbObjectWriter Writer;
 	Writer << "BucketId"sv << m_BucketId;
@@ -884,7 +888,7 @@ ValidateCacheBucketEntryValue(ZenContentType ContentType, IoBuffer Buffer)
 void
 ZenCacheDiskLayer::CacheBucket::ScrubStorage(ScrubContext& Ctx)
 {
-	ZEN_TRACE_CPU("Z$::Bucket::Scrub");
+	ZEN_TRACE_CPU("Z$::Disk::Bucket::Scrub");
 
 	ZEN_INFO("scrubbing '{}'", m_BucketDir);
 
@@ -1123,7 +1127,7 @@ ZenCacheDiskLayer::CacheBucket::ScrubStorage(ScrubContext& Ctx)
 void
 ZenCacheDiskLayer::CacheBucket::GatherReferences(GcContext& GcCtx)
 {
-	ZEN_TRACE_CPU("Z$::DiskLayer::CacheBucket::GatherReferences");
+	ZEN_TRACE_CPU("Z$::Disk::Bucket::GatherReferences");
 
 	uint64_t WriteBlockTimeUs		 = 0;
 	uint64_t WriteBlockLongestTimeUs = 0;
@@ -1225,7 +1229,7 @@ ZenCacheDiskLayer::CacheBucket::GatherReferences(GcContext& GcCtx)
 void
 ZenCacheDiskLayer::CacheBucket::CollectGarbage(GcContext& GcCtx)
 {
-	ZEN_TRACE_CPU("Z$::DiskLayer::CacheBucket::CollectGarbage");
+	ZEN_TRACE_CPU("Z$::Disk::Bucket::CollectGarbage");
 
 	ZEN_DEBUG("collecting garbage from '{}'", m_BucketDir);
 
@@ -1320,6 +1324,8 @@ ZenCacheDiskLayer::CacheBucket::CollectGarbage(GcContext& GcCtx)
 	IndexMap						 Index;
 	BlockStore::ReclaimSnapshotState BlockStoreState;
 	{
+		ZEN_TRACE_CPU("Z$::Disk::Bucket::CollectGarbage::State");
+
 		RwLock::SharedLockScope __(m_IndexLock);
 		Stopwatch				Timer;
 		const auto				____ = MakeGuard([&] {
@@ -1364,6 +1370,8 @@ ZenCacheDiskLayer::CacheBucket::CollectGarbage(GcContext& GcCtx)
 
 	if (GcCtx.IsDeletionMode())
 	{
+		ZEN_TRACE_CPU("Z$::Disk::Bucket::CollectGarbage::Delete");
+
 		std::error_code			   Ec;
 		ExtendablePathBuilder<256> Path;
 
@@ -1545,6 +1553,8 @@ ZenCacheDiskLayer::CacheBucket::CollectGarbage(GcContext& GcCtx)
 void
 ZenCacheDiskLayer::CacheBucket::UpdateAccessTimes(const std::vector<zen::access_tracking::KeyAccessTime>& AccessTimes)
 {
+	ZEN_TRACE_CPU("Z$::Disk::Bucket::UpdateAccessTimes");
+
 	using namespace access_tracking;
 
 	for (const KeyAccessTime& KeyTime : AccessTimes)
@@ -1612,6 +1622,8 @@ ZenCacheDiskLayer::CacheBucket::GetValueDetails(const std::string_view ValueFilt
 void
 ZenCacheDiskLayer::CollectGarbage(GcContext& GcCtx)
 {
+	ZEN_TRACE_CPU("Z$::Disk::CollectGarbage");
+
 	RwLock::SharedLockScope _(m_Lock);
 
 	for (auto& Kv : m_Buckets)
@@ -1639,7 +1651,7 @@ ZenCacheDiskLayer::UpdateAccessTimes(const zen::access_tracking::AccessTimes& Ac
 void
 ZenCacheDiskLayer::CacheBucket::PutStandaloneCacheValue(const IoHash& HashKey, const ZenCacheValue& Value)
 {
-	ZEN_TRACE_CPU("Z$::Bucket::PutStandaloneCacheValue");
+	ZEN_TRACE_CPU("Z$::Disk::Bucket::PutStandaloneCacheValue");
 
 	uint64_t NewFileSize = Value.Value.Size();
 
@@ -1777,6 +1789,8 @@ ZenCacheDiskLayer::CacheBucket::PutStandaloneCacheValue(const IoHash& HashKey, c
 void
 ZenCacheDiskLayer::CacheBucket::PutInlineCacheValue(const IoHash& HashKey, const ZenCacheValue& Value)
 {
+	ZEN_TRACE_CPU("Z$::Disk::Bucket::PutInlineCacheValue");
+
 	uint8_t EntryFlags = 0;
 
 	if (Value.Value.GetContentType() == ZenContentType::kCbObject)
@@ -1824,6 +1838,8 @@ ZenCacheDiskLayer::~ZenCacheDiskLayer() = default;
 bool
 ZenCacheDiskLayer::Get(std::string_view InBucket, const IoHash& HashKey, ZenCacheValue& OutValue)
 {
+	ZEN_TRACE_CPU("Z$::Disk::Get");
+
 	const auto	 BucketName = std::string(InBucket);
 	CacheBucket* Bucket		= nullptr;
 
@@ -1871,6 +1887,8 @@ ZenCacheDiskLayer::Get(std::string_view InBucket, const IoHash& HashKey, ZenCach
 void
 ZenCacheDiskLayer::Put(std::string_view InBucket, const IoHash& HashKey, const ZenCacheValue& Value)
 {
+	ZEN_TRACE_CPU("Z$::Disk::Put");
+
 	const auto	 BucketName = std::string(InBucket);
 	CacheBucket* Bucket		= nullptr;
 
@@ -2060,6 +2078,8 @@ ZenCacheDiskLayer::ScrubStorage(ScrubContext& Ctx)
 void
 ZenCacheDiskLayer::GatherReferences(GcContext& GcCtx)
 {
+	ZEN_TRACE_CPU("Z$::Disk::GatherReferences");
+
 	RwLock::SharedLockScope _(m_Lock);
 
 	for (auto& Kv : m_Buckets)
diff --git a/src/zenserver/cache/cachememorylayer.cpp b/src/zenserver/cache/cachememorylayer.cpp
index 1ef581ba5..c18db7706 100644
--- a/src/zenserver/cache/cachememorylayer.cpp
+++ b/src/zenserver/cache/cachememorylayer.cpp
@@ -4,6 +4,7 @@
 
 #include <zencore/compactbinaryvalidation.h>
 #include <zencore/compress.h>
+#include <zencore/trace.h>
 
 //////////////////////////////////////////////////////////////////////////
 
@@ -20,6 +21,8 @@ ZenCacheMemoryLayer::~ZenCacheMemoryLayer()
 bool
 ZenCacheMemoryLayer::Get(std::string_view InBucket, const IoHash& HashKey, ZenCacheValue& OutValue)
 {
+	ZEN_TRACE_CPU("Z$::Mem::Get");
+
 	RwLock::SharedLockScope _(m_Lock);
 
 	auto It = m_Buckets.find(std::string(InBucket));
@@ -43,6 +46,8 @@ ZenCacheMemoryLayer::Get(std::string_view InBucket, const IoHash& HashKey, ZenCa
 void
 ZenCacheMemoryLayer::Put(std::string_view InBucket, const IoHash& HashKey, const ZenCacheValue& Value)
 {
+	ZEN_TRACE_CPU("Z$::Mem::Put");
+
 	const auto	 BucketName = std::string(InBucket);
 	CacheBucket* Bucket		= nullptr;
 
@@ -240,6 +245,8 @@ ZenCacheMemoryLayer::CacheBucket::GatherAccessTimes(std::vector<zen::access_trac
 bool
 ZenCacheMemoryLayer::CacheBucket::Get(const IoHash& HashKey, ZenCacheValue& OutValue)
 {
+	ZEN_TRACE_CPU("Z$::Mem::Bucket::Get");
+
 	RwLock::SharedLockScope _(m_BucketLock);
 
 	if (auto It = m_CacheMap.find(HashKey); It != m_CacheMap.end())
@@ -261,6 +268,8 @@ ZenCacheMemoryLayer::CacheBucket::Get(const IoHash& HashKey, ZenCacheValue& OutV
 void
 ZenCacheMemoryLayer::CacheBucket::Put(const IoHash& HashKey, const ZenCacheValue& Value)
 {
+	ZEN_TRACE_CPU("Z$::Mem::Bucket::Put");
+
 	size_t PayloadSize = Value.Value.GetSize();
 	{
 		GcClock::Tick			   AccessTime = GcClock::TickCount();
diff --git a/src/zenserver/cache/httpstructuredcache.cpp b/src/zenserver/cache/httpstructuredcache.cpp
index 7f1ce18f9..32e8c1f98 100644
--- a/src/zenserver/cache/httpstructuredcache.cpp
+++ b/src/zenserver/cache/httpstructuredcache.cpp
@@ -603,7 +603,10 @@ HttpStructuredCacheService::HandleDetailsRequest(HttpServerRequest& Request)
 void
 HttpStructuredCacheService::HandleRequest(HttpServerRequest& Request)
 {
+	ZEN_TRACE_CPU("z$::Http::HandleRequest");
+
 	m_CacheStats.RequestCount++;
+
 	metrics::OperationTiming::Scope $(m_HttpRequests);
 
 	std::string_view Key = Request.RelativeUri();
@@ -1599,6 +1602,8 @@ HttpStructuredCacheService::HandleRpcRequest(const CacheRequestContext& Context,
 											 int&						OutTargetProcessId,
 											 CbPackage&					OutResultPackage)
 {
+	ZEN_TRACE_CPU("Z$::HandleRpcRequest");
+
 	CbPackage	 Package;
 	CbObjectView Object;
 	CbObject	 ObjectBuffer;
@@ -1719,6 +1724,7 @@ HttpStructuredCacheService::ReplayRequestRecorder(const CacheRequestContext&  Co
 void
 HttpStructuredCacheService::HandleRpcRequest(HttpServerRequest& Request)
 {
+	ZEN_TRACE_CPU("z$::Http::HandleRpcRequest");
 	switch (Request.RequestVerb())
 	{
 		case HttpVerb::kPost:
@@ -2020,6 +2026,8 @@ HttpStructuredCacheService::HandleRpcGetCacheRecords(const CacheRequestContext&
 
 	for (CbFieldView RequestField : RequestsArray)
 	{
+		ZEN_TRACE_CPU("Z$::RpcGetCacheRecords::Request");
+
 		Stopwatch		   Timer;
 		RecordRequestData& Request		 = Requests.emplace_back();
 		CbObjectView	   RequestObject = RequestField.AsObjectView();
@@ -2245,70 +2253,74 @@ HttpStructuredCacheService::HandleRpcGetCacheRecords(const CacheRequestContext&
 		m_UpstreamCache.GetCacheRecords(*Namespace, UpstreamRequests, std::move(OnCacheRecordGetComplete));
 	}
 
-	CbPackage	   ResponsePackage;
-	CbObjectWriter ResponseObject;
-
-	ResponseObject.BeginArray("Result"sv);
-	for (RecordRequestData& Request : Requests)
 	{
-		const CacheKey& Key = Request.Upstream.Key;
-		if (Request.Complete ||
-			(Request.RecordObject && EnumHasAllFlags(Request.DownstreamPolicy.GetRecordPolicy(), CachePolicy::PartialRecord)))
+		ZEN_TRACE_CPU("Z$::RpcGetCacheRecords::Response");
+		CbPackage	   ResponsePackage;
+		CbObjectWriter ResponseObject;
+
+		ResponseObject.BeginArray("Result"sv);
+		for (RecordRequestData& Request : Requests)
 		{
-			ResponseObject << Request.RecordObject;
-			for (ValueRequestData& Value : Request.Values)
+			const CacheKey& Key = Request.Upstream.Key;
+			if (Request.Complete ||
+				(Request.RecordObject && EnumHasAllFlags(Request.DownstreamPolicy.GetRecordPolicy(), CachePolicy::PartialRecord)))
 			{
-				if (!EnumHasAllFlags(Value.DownstreamPolicy, CachePolicy::SkipData) && Value.Payload)
+				ResponseObject << Request.RecordObject;
+				for (ValueRequestData& Value : Request.Values)
 				{
-					ResponsePackage.AddAttachment(CbAttachment(Value.Payload, Value.ContentId));
+					if (!EnumHasAllFlags(Value.DownstreamPolicy, CachePolicy::SkipData) && Value.Payload)
+					{
+						ResponsePackage.AddAttachment(CbAttachment(Value.Payload, Value.ContentId));
+					}
 				}
-			}
 
-			ZEN_DEBUG("GETCACHERECORD HIT - '{}/{}/{}' {}{} ({}) in {}",
-					  *Namespace,
-					  Key.Bucket,
-					  Key.Hash,
-					  NiceBytes(Request.RecordCacheValue.Size()),
-					  Request.Complete ? ""sv : " (PARTIAL)"sv,
-					  Request.Source ? Request.Source->Url : "LOCAL"sv,
-					  NiceLatencyNs(Request.ElapsedTimeUs * 1000));
-			m_CacheStats.HitCount++;
-			m_CacheStats.UpstreamHitCount += Request.Source ? 1 : 0;
-		}
-		else
-		{
-			ResponseObject.AddNull();
-
-			if (!EnumHasAnyFlags(Request.DownstreamPolicy.GetRecordPolicy(), CachePolicy::Query))
-			{
-				// If they requested no query, do not record this as a miss
-				ZEN_DEBUG("GETCACHERECORD DISABLEDQUERY - '{}/{}/{}' in {}",
+				ZEN_DEBUG("GETCACHERECORD HIT - '{}/{}/{}' {}{} ({}) in {}",
 						  *Namespace,
 						  Key.Bucket,
 						  Key.Hash,
+						  NiceBytes(Request.RecordCacheValue.Size()),
+						  Request.Complete ? ""sv : " (PARTIAL)"sv,
+						  Request.Source ? Request.Source->Url : "LOCAL"sv,
 						  NiceLatencyNs(Request.ElapsedTimeUs * 1000));
+				m_CacheStats.HitCount++;
+				m_CacheStats.UpstreamHitCount += Request.Source ? 1 : 0;
 			}
 			else
 			{
-				ZEN_DEBUG("GETCACHERECORD MISS - '{}/{}/{}'{} ({}) in {}",
-						  *Namespace,
-						  Key.Bucket,
-						  Key.Hash,
-						  Request.RecordObject ? ""sv : " (PARTIAL)"sv,
-						  Request.Source ? Request.Source->Url : "LOCAL"sv,
-						  NiceLatencyNs(Request.ElapsedTimeUs * 1000));
-				m_CacheStats.MissCount++;
+				ResponseObject.AddNull();
+
+				if (!EnumHasAnyFlags(Request.DownstreamPolicy.GetRecordPolicy(), CachePolicy::Query))
+				{
+					// If they requested no query, do not record this as a miss
+					ZEN_DEBUG("GETCACHERECORD DISABLEDQUERY - '{}/{}/{}' in {}",
+							  *Namespace,
+							  Key.Bucket,
+							  Key.Hash,
+							  NiceLatencyNs(Request.ElapsedTimeUs * 1000));
+				}
+				else
+				{
+					ZEN_DEBUG("GETCACHERECORD MISS - '{}/{}/{}'{} ({}) in {}",
+							  *Namespace,
+							  Key.Bucket,
+							  Key.Hash,
+							  Request.RecordObject ? ""sv : " (PARTIAL)"sv,
+							  Request.Source ? Request.Source->Url : "LOCAL"sv,
+							  NiceLatencyNs(Request.ElapsedTimeUs * 1000));
+					m_CacheStats.MissCount++;
+				}
 			}
 		}
+		ResponseObject.EndArray();
+		ResponsePackage.SetObject(ResponseObject.Save());
+		return ResponsePackage;
 	}
-	ResponseObject.EndArray();
-	ResponsePackage.SetObject(ResponseObject.Save());
-	return ResponsePackage;
 }
 
 CbPackage
 HttpStructuredCacheService::HandleRpcPutCacheValues(const CacheRequestContext& Context, const CbPackage& BatchRequest)
 {
+	ZEN_TRACE_CPU("Z$::RpcPutCacheValues");
 	CbObjectView BatchObject = BatchRequest.GetObject();
 	CbObjectView Params		 = BatchObject["Params"sv].AsObjectView();
 
@@ -2324,6 +2336,8 @@ HttpStructuredCacheService::HandleRpcPutCacheValues(const CacheRequestContext& C
 	std::vector<bool> Results;
 	for (CbFieldView RequestField : Params["Requests"sv])
 	{
+		ZEN_TRACE_CPU("Z$::RpcPutCacheValues::Request");
+
 		Stopwatch Timer;
 
 		CbObjectView RequestObject = RequestField.AsObjectView();
@@ -2404,23 +2418,27 @@ HttpStructuredCacheService::HandleRpcPutCacheValues(const CacheRequestContext& C
 		return CbPackage{};
 	}
 
-	CbObjectWriter ResponseObject;
-	ResponseObject.BeginArray("Result"sv);
-	for (bool Value : Results)
 	{
-		ResponseObject.AddBool(Value);
-	}
-	ResponseObject.EndArray();
+		ZEN_TRACE_CPU("Z$::RpcPutCacheValues::Response");
+		CbObjectWriter ResponseObject;
+		ResponseObject.BeginArray("Result"sv);
+		for (bool Value : Results)
+		{
+			ResponseObject.AddBool(Value);
+		}
+		ResponseObject.EndArray();
 
-	CbPackage RpcResponse;
-	RpcResponse.SetObject(ResponseObject.Save());
+		CbPackage RpcResponse;
+		RpcResponse.SetObject(ResponseObject.Save());
 
-	return RpcResponse;
+		return RpcResponse;
+	}
 }
 
 CbPackage
 HttpStructuredCacheService::HandleRpcGetCacheValues(const CacheRequestContext& Context, CbObjectView RpcRequest)
 {
+	ZEN_TRACE_CPU("Z$::RpcGetCacheValues");
 	ZEN_ASSERT(RpcRequest["Method"sv].AsString() == "GetCacheValues"sv);
 
 	CbObjectView			   Params		 = RpcRequest["Params"sv].AsObjectView();
@@ -2450,6 +2468,8 @@ HttpStructuredCacheService::HandleRpcGetCacheValues(const CacheRequestContext& C
 
 	for (CbFieldView RequestField : RequestView)
 	{
+		ZEN_TRACE_CPU("Z$::RpcGetCacheValues::Request");
+
 		Stopwatch Timer;
 
 		RequestData& Request	   = Requests.emplace_back();
@@ -2584,38 +2604,41 @@ HttpStructuredCacheService::HandleRpcGetCacheValues(const CacheRequestContext& C
 		return CbPackage{};
 	}
 
-	CbPackage	   RpcResponse;
-	CbObjectWriter ResponseObject;
-	ResponseObject.BeginArray("Result"sv);
-	for (const RequestData& Request : Requests)
 	{
-		ResponseObject.BeginObject();
+		ZEN_TRACE_CPU("Z$::RpcGetCacheValues::Response");
+		CbPackage	   RpcResponse;
+		CbObjectWriter ResponseObject;
+		ResponseObject.BeginArray("Result"sv);
+		for (const RequestData& Request : Requests)
 		{
-			const CompressedBuffer& Result = Request.Result;
-			if (Result)
+			ResponseObject.BeginObject();
 			{
-				ResponseObject.AddHash("RawHash"sv, Request.RawHash);
-				if (!EnumHasAllFlags(Request.Policy, CachePolicy::SkipData))
+				const CompressedBuffer& Result = Request.Result;
+				if (Result)
 				{
-					RpcResponse.AddAttachment(CbAttachment(Result, Request.RawHash));
+					ResponseObject.AddHash("RawHash"sv, Request.RawHash);
+					if (!EnumHasAllFlags(Request.Policy, CachePolicy::SkipData))
+					{
+						RpcResponse.AddAttachment(CbAttachment(Result, Request.RawHash));
+					}
+					else
+					{
+						ResponseObject.AddInteger("RawSize"sv, Request.RawSize);
+					}
 				}
-				else
+				else if (Request.RawHash != IoHash::Zero)
 				{
+					ResponseObject.AddHash("RawHash"sv, Request.RawHash);
 					ResponseObject.AddInteger("RawSize"sv, Request.RawSize);
 				}
 			}
-			else if (Request.RawHash != IoHash::Zero)
-			{
-				ResponseObject.AddHash("RawHash"sv, Request.RawHash);
-				ResponseObject.AddInteger("RawSize"sv, Request.RawSize);
-			}
+			ResponseObject.EndObject();
 		}
-		ResponseObject.EndObject();
-	}
-	ResponseObject.EndArray();
+		ResponseObject.EndArray();
 
-	RpcResponse.SetObject(ResponseObject.Save());
-	return RpcResponse;
+		RpcResponse.SetObject(ResponseObject.Save());
+		return RpcResponse;
+	}
 }
 
 namespace cache::detail {
@@ -2657,6 +2680,7 @@ namespace cache::detail {
 CbPackage
 HttpStructuredCacheService::HandleRpcGetCacheChunks(const CacheRequestContext& Context, CbObjectView RpcRequest)
 {
+	ZEN_TRACE_CPU("Z$::RpcGetCacheChunks");
 	using namespace cache::detail;
 
 	std::string						Namespace;
@@ -2698,6 +2722,8 @@ HttpStructuredCacheService::ParseGetCacheChunksRequest(std::string&								  Nam
 													   std::vector<cache::detail::ChunkRequest*>& ValueRequests,
 													   CbObjectView								  RpcRequest)
 {
+	ZEN_TRACE_CPU("Z$::ParseGetCacheChunksRequest");
+
 	using namespace cache::detail;
 
 	ZEN_ASSERT(RpcRequest["Method"sv].AsString() == "GetCacheChunks"sv);
@@ -2731,6 +2757,8 @@ HttpStructuredCacheService::ParseGetCacheChunksRequest(std::string&								  Nam
 
 	for (CbFieldView RequestView : ChunkRequestsArray)
 	{
+		ZEN_TRACE_CPU("Z$::ParseGetCacheChunksRequest::Request");
+
 		CbObjectView	   RequestObject = RequestView.AsObjectView();
 		CacheChunkRequest& RequestKey	 = RequestKeys.emplace_back();
 		ChunkRequest&	   Request		 = Requests.emplace_back();
@@ -2809,12 +2837,16 @@ HttpStructuredCacheService::GetLocalCacheRecords(const CacheRequestContext&
 												 std::vector<cache::detail::ChunkRequest*>& RecordRequests,
 												 std::vector<CacheChunkRequest*>&			OutUpstreamChunks)
 {
+	ZEN_TRACE_CPU("Z$::GetLocalCacheRecords");
+
 	using namespace cache::detail;
 	const bool HasUpstream = m_UpstreamCache.IsActive();
 
 	std::vector<CacheKeyRequest*> UpstreamRecordRequests;
 	for (size_t RecordIndex = 0; RecordIndex < Records.size(); ++RecordIndex)
 	{
+		ZEN_TRACE_CPU("Z$::GetLocalCacheRecords::Record");
+
 		Stopwatch		 Timer;
 		CacheKeyRequest& RecordKey = RecordKeys[RecordIndex];
 		RecordBody&		 Record	   = Records[RecordIndex];
@@ -2872,6 +2904,8 @@ HttpStructuredCacheService::GetLocalCacheRecords(const CacheRequestContext&
 
 	for (ChunkRequest* Request : RecordRequests)
 	{
+		ZEN_TRACE_CPU("Z$::GetLocalCacheRecords::Chunk");
+
 		Stopwatch Timer;
 		if (Request->Key->ChunkId == IoHash::Zero)
 		{
@@ -2962,11 +2996,15 @@ HttpStructuredCacheService::GetLocalCacheValues(const CacheRequestContext&
 												std::vector<cache::detail::ChunkRequest*>& ValueRequests,
 												std::vector<CacheChunkRequest*>&		   OutUpstreamChunks)
 {
+	ZEN_TRACE_CPU("Z$::GetLocalCacheValues");
+
 	using namespace cache::detail;
 	const bool HasUpstream = m_UpstreamCache.IsActive();
 
 	for (ChunkRequest* Request : ValueRequests)
 	{
+		ZEN_TRACE_CPU("Z$::GetLocalCacheValues::Value");
+
 		Stopwatch Timer;
 		if (!Request->Exists && EnumHasAllFlags(Request->DownstreamPolicy, CachePolicy::QueryLocal))
 		{
@@ -3007,62 +3045,65 @@ HttpStructuredCacheService::GetUpstreamCacheChunks(const CacheRequestContext&
 												   std::vector<CacheChunkRequest>&			 RequestKeys,
 												   std::vector<cache::detail::ChunkRequest>& Requests)
 {
+	if (UpstreamChunks.empty())
+	{
+		return;
+	}
+	ZEN_TRACE_CPU("Z$::GetUpstreamCacheChunks");
+
 	using namespace cache::detail;
 
-	if (!UpstreamChunks.empty())
-	{
-		const auto OnCacheChunksGetComplete = [this, Namespace, &RequestKeys, &Requests, Context](CacheChunkGetCompleteParams&& Params) {
-			if (Params.RawHash == Params.RawHash.Zero)
+	const auto OnCacheChunksGetComplete = [this, Namespace, &RequestKeys, &Requests, Context](CacheChunkGetCompleteParams&& Params) {
+		if (Params.RawHash == Params.RawHash.Zero)
+		{
+			return;
+		}
+
+		CacheChunkRequest& Key			= Params.Request;
+		size_t			   RequestIndex = std::distance(RequestKeys.data(), &Key);
+		ChunkRequest&	   Request		= Requests[RequestIndex];
+		Request.ElapsedTimeUs += static_cast<uint64_t>(Params.ElapsedSeconds * 1000000.0);
+		if (EnumHasAllFlags(Request.DownstreamPolicy, CachePolicy::StoreLocal) ||
+			!EnumHasAllFlags(Request.DownstreamPolicy, CachePolicy::SkipData))
+		{
+			CompressedBuffer Compressed = CompressedBuffer::FromCompressedNoValidate(IoBuffer(Params.Value));
+			if (!Compressed)
 			{
 				return;
 			}
 
-			CacheChunkRequest& Key			= Params.Request;
-			size_t			   RequestIndex = std::distance(RequestKeys.data(), &Key);
-			ChunkRequest&	   Request		= Requests[RequestIndex];
-			Request.ElapsedTimeUs += static_cast<uint64_t>(Params.ElapsedSeconds * 1000000.0);
-			if (EnumHasAllFlags(Request.DownstreamPolicy, CachePolicy::StoreLocal) ||
-				!EnumHasAllFlags(Request.DownstreamPolicy, CachePolicy::SkipData))
+			bool StoreLocal = EnumHasAllFlags(Request.DownstreamPolicy, CachePolicy::StoreLocal) && AreDiskWritesAllowed();
+			if (StoreLocal)
 			{
-				CompressedBuffer Compressed = CompressedBuffer::FromCompressedNoValidate(IoBuffer(Params.Value));
-				if (!Compressed)
+				if (Request.IsRecordRequest)
 				{
-					return;
-				}
-
-				bool StoreLocal = EnumHasAllFlags(Request.DownstreamPolicy, CachePolicy::StoreLocal) && AreDiskWritesAllowed();
-				if (StoreLocal)
-				{
-					if (Request.IsRecordRequest)
-					{
-						m_CidStore.AddChunk(Params.Value, Params.RawHash);
-					}
-					else
-					{
-						m_CacheStore.Put(Context,
-										 Namespace,
-										 Key.Key.Bucket,
-										 Key.Key.Hash,
-										 {.Value = Params.Value, .RawSize = Params.RawSize, .RawHash = Params.RawHash});
-						m_CacheStats.WriteCount++;
-					}
+					m_CidStore.AddChunk(Params.Value, Params.RawHash);
 				}
-				if (!EnumHasAllFlags(Request.DownstreamPolicy, CachePolicy::SkipData))
+				else
 				{
-					Request.Value = std::move(Compressed);
+					m_CacheStore.Put(Context,
+									 Namespace,
+									 Key.Key.Bucket,
+									 Key.Key.Hash,
+									 {.Value = Params.Value, .RawSize = Params.RawSize, .RawHash = Params.RawHash});
+					m_CacheStats.WriteCount++;
 				}
 			}
-			Key.ChunkId			 = Params.RawHash;
-			Request.Exists		 = true;
-			Request.RawSize		 = Params.RawSize;
-			Request.RawSizeKnown = true;
-			Request.Source		 = Params.Source;
+			if (!EnumHasAllFlags(Request.DownstreamPolicy, CachePolicy::SkipData))
+			{
+				Request.Value = std::move(Compressed);
+			}
+		}
+		Key.ChunkId			 = Params.RawHash;
+		Request.Exists		 = true;
+		Request.RawSize		 = Params.RawSize;
+		Request.RawSizeKnown = true;
+		Request.Source		 = Params.Source;
 
-			m_CacheStats.UpstreamHitCount++;
-		};
+		m_CacheStats.UpstreamHitCount++;
+	};
 
-		m_UpstreamCache.GetCacheChunks(Namespace, UpstreamChunks, std::move(OnCacheChunksGetComplete));
-	}
+	m_UpstreamCache.GetCacheChunks(Namespace, UpstreamChunks, std::move(OnCacheChunksGetComplete));
 }
 
 CbPackage
@@ -3070,6 +3111,8 @@ HttpStructuredCacheService::WriteGetCacheChunksResponse([[maybe_unused]] const C
 														std::string_view							Namespace,
 														std::vector<cache::detail::ChunkRequest>&	Requests)
 {
+	ZEN_TRACE_CPU("Z$::WriteGetCacheChunksResponse");
+
 	using namespace cache::detail;
 
 	CbPackage	   RpcResponse;
@@ -3078,6 +3121,8 @@ HttpStructuredCacheService::WriteGetCacheChunksResponse([[maybe_unused]] const C
 	Writer.BeginArray("Result"sv);
 	for (ChunkRequest& Request : Requests)
 	{
+		ZEN_TRACE_CPU("Z$::WriteGetCacheChunksResponse::Request");
+
 		Writer.BeginObject();
 		{
 			if (Request.Exists)
diff --git a/src/zenserver/cache/structuredcachestore.cpp b/src/zenserver/cache/structuredcachestore.cpp
index 56e83eef2..2ba1f61bd 100644
--- a/src/zenserver/cache/structuredcachestore.cpp
+++ b/src/zenserver/cache/structuredcachestore.cpp
@@ -61,7 +61,7 @@ ZenCacheNamespace::~ZenCacheNamespace()
 bool
 ZenCacheNamespace::Get(std::string_view InBucket, const IoHash& HashKey, ZenCacheValue& OutValue)
 {
-	ZEN_TRACE_CPU("Z$::Get");
+	ZEN_TRACE_CPU("Z$::Namespace::Get");
 
 	bool Ok = m_MemLayer.Get(InBucket, HashKey, OutValue);
 
@@ -90,7 +90,7 @@ ZenCacheNamespace::Get(std::string_view InBucket, const IoHash& HashKey, ZenCach
 void
 ZenCacheNamespace::Put(std::string_view InBucket, const IoHash& HashKey, const ZenCacheValue& Value)
 {
-	ZEN_TRACE_CPU("Z$::Put");
+	ZEN_TRACE_CPU("Z$::Namespace::Put");
 
 	// Store value and index
 
@@ -152,6 +152,8 @@ ZenCacheNamespace::ScrubStorage(ScrubContext& Ctx)
 void
 ZenCacheNamespace::GatherReferences(GcContext& GcCtx)
 {
+	ZEN_TRACE_CPU("Z$::ZenCacheNamespace::GatherReferences");
+
 	Stopwatch  Timer;
 	const auto Guard =
 		MakeGuard([&] { ZEN_DEBUG("cache gathered all references from '{}' in {}", m_RootDir, NiceTimeSpanMs(Timer.GetElapsedTimeMs())); });
@@ -166,6 +168,8 @@ ZenCacheNamespace::GatherReferences(GcContext& GcCtx)
 void
 ZenCacheNamespace::CollectGarbage(GcContext& GcCtx)
 {
+	ZEN_TRACE_CPU("Z$::Namespace::CollectGarbage");
+
 	m_MemLayer.Reset();
 	m_DiskLayer.CollectGarbage(GcCtx);
 }
@@ -354,6 +358,8 @@ ZenCacheStore::Get(const CacheRequestContext& Context,
 				   const IoHash&			  HashKey,
 				   ZenCacheValue&			  OutValue)
 {
+	ZEN_TRACE_CPU("Z$::Get");
+
 	if (ZenCacheNamespace* Store = GetNamespace(Namespace); Store)
 	{
 		bool Result = Store->Get(Bucket, HashKey, OutValue);
@@ -396,6 +402,8 @@ ZenCacheStore::Put(const CacheRequestContext& Context,
 				   const IoHash&			  HashKey,
 				   const ZenCacheValue&		  Value)
 {
+	ZEN_TRACE_CPU("Z$::Put");
+
 	if (m_Configuration.EnableWriteLog)
 	{
 		ZEN_TRACE_CPU("Z$::Get::WriteLog");
diff --git a/src/zenserver/projectstore/projectstore.cpp b/src/zenserver/projectstore/projectstore.cpp
index 2fd6d492e..9be600e4e 100644
--- a/src/zenserver/projectstore/projectstore.cpp
+++ b/src/zenserver/projectstore/projectstore.cpp
@@ -267,6 +267,8 @@ struct ProjectStore::OplogStorage : public RefCounted
 
 	void Open(bool IsCreate)
 	{
+		ZEN_TRACE_CPU("Store::OplogStorage::Open");
+
 		using namespace std::literals;
 
 		ZEN_INFO("initializing oplog storage at '{}'", m_OplogStoragePath);
@@ -288,7 +290,7 @@ struct ProjectStore::OplogStorage : public RefCounted
 
 	void ReplayLog(std::function<void(CbObject, const OplogEntry&)>&& Handler)
 	{
-		ZEN_TRACE_CPU("ProjectStore::OplogStorage::ReplayLog");
+		ZEN_TRACE_CPU("Store::OplogStorage::ReplayLog");
 
 		// This could use memory mapping or do something clever but for now it just reads the file sequentially
 
@@ -359,8 +361,7 @@ struct ProjectStore::OplogStorage : public RefCounted
 				InvalidEntries++;
 				continue;
 			}
-			CbObject Op(SharedBuffer::MakeView(OpBuffer.Data(), LogEntry.OpCoreSize));
-			Handler(Op, LogEntry);
+			Handler(CbObject(SharedBuffer::MakeView(OpBuffer.Data(), LogEntry.OpCoreSize)), LogEntry);
 		}
 
 		if (InvalidEntries)
@@ -374,9 +375,9 @@ struct ProjectStore::OplogStorage : public RefCounted
 				 m_NextOpsOffset.load());
 	}
 
-	void ReplayLog(const std::span<OplogEntryAddress> Entries, std::function<void(CbObject)>&& Handler)
+	void ReplayLogEntries(const std::span<OplogEntryAddress> Entries, std::function<void(CbObject)>&& Handler)
 	{
-		ZEN_TRACE_CPU("Store::OplogStorage::ReplayLog");
+		ZEN_TRACE_CPU("Store::OplogStorage::ReplayLogEntries");
 
 		BasicFileBuffer OpBlobsBuffer(m_OpBlobs, 65536);
 		IoBuffer		OpBuffer(512);
@@ -389,12 +390,14 @@ struct ProjectStore::OplogStorage : public RefCounted
 				OpBuffer = IoBuffer(Entry.Size);
 			}
 			OpBlobsBuffer.Read((void*)OpBuffer.Data(), Entry.Size, OpFileOffset);
-			Handler(CbObject(SharedBuffer(OpBuffer)));
+			Handler(CbObject(SharedBuffer::MakeView(OpBuffer.Data(), Entry.Size)));
 		}
 	}
 
 	CbObject GetOp(const OplogEntryAddress& Entry)
 	{
+		ZEN_TRACE_CPU("Store::OplogStorage::GetOp");
+
 		IoBuffer OpBuffer(Entry.Size);
 
 		const uint64_t OpFileOffset = Entry.Offset * m_OpsAlign;
@@ -405,7 +408,7 @@ struct ProjectStore::OplogStorage : public RefCounted
 
 	OplogEntry AppendOp(SharedBuffer Buffer, uint32_t OpCoreHash, XXH3_128 KeyHash)
 	{
-		ZEN_TRACE_CPU("ProjectStore::OplogStorage::AppendOp");
+		ZEN_TRACE_CPU("Store::OplogStorage::AppendOp");
 
 		using namespace std::literals;
 
@@ -498,7 +501,7 @@ ProjectStore::Oplog::ScrubStorage(ScrubContext& Ctx) const
 void
 ProjectStore::Oplog::GatherReferences(GcContext& GcCtx)
 {
-	ZEN_TRACE_CPU("ProjectStore::Oplog::GatherReferences");
+	ZEN_TRACE_CPU("Store::Oplog::GatherReferences");
 
 	tsl::robin_set<IoHash> AttachmentHashes;
 	IterateOplog([&](CbObject Op) {
@@ -728,7 +731,7 @@ ProjectStore::Oplog::IterateOplog(std::function<void(CbObject)>&& Handler)
 		return Lhs.Offset < Rhs.Offset;
 	});
 
-	m_Storage->ReplayLog(Entries, [&](CbObject Op) { Handler(Op); });
+	m_Storage->ReplayLogEntries(Entries, [&](CbObject Op) { Handler(Op); });
 }
 
 void
@@ -773,7 +776,7 @@ ProjectStore::Oplog::IterateOplogWithKey(std::function<void(int, const Oid&, CbO
 	}
 
 	size_t EntryIndex = 0;
-	m_Storage->ReplayLog(SortedEntries, [&](CbObject Op) {
+	m_Storage->ReplayLogEntries(SortedEntries, [&](CbObject Op) {
 		Handler(LSNs[EntryIndex], Keys[EntryIndex], Op);
 		EntryIndex++;
 	});
@@ -975,7 +978,7 @@ ProjectStore::Oplog::RegisterOplogEntry(RwLock::ExclusiveLockScope& OplogLock,
 										const OplogEntryMapping&	OpMapping,
 										const OplogEntry&			OpEntry)
 {
-	ZEN_TRACE_CPU("ProjectStore::Oplog::RegisterOplogEntry");
+	ZEN_TRACE_CPU("Store::Oplog::RegisterOplogEntry");
 
 	// For now we're assuming the update is all in-memory so we can hold an exclusive lock without causing
 	// too many problems. Longer term we'll probably want to ensure we can do concurrent updates however
@@ -1007,7 +1010,7 @@ ProjectStore::Oplog::RegisterOplogEntry(RwLock::ExclusiveLockScope& OplogLock,
 uint32_t
 ProjectStore::Oplog::AppendNewOplogEntry(CbPackage OpPackage)
 {
-	ZEN_TRACE_CPU("ProjectStore::Oplog::AppendNewOplogEntry");
+	ZEN_TRACE_CPU("Store::Oplog::AppendNewOplogEntry");
 
 	const CbObject& Core	= OpPackage.GetObject();
 	const uint32_t	EntryId = AppendNewOplogEntry(Core);
@@ -1047,7 +1050,7 @@ ProjectStore::Oplog::AppendNewOplogEntry(CbPackage OpPackage)
 uint32_t
 ProjectStore::Oplog::AppendNewOplogEntry(CbObject Core)
 {
-	ZEN_TRACE_CPU("ProjectStore::Oplog::AppendNewOplogEntry");
+	ZEN_TRACE_CPU("Store::Oplog::AppendNewOplogEntry");
 
 	using namespace std::literals;
 
@@ -1108,7 +1111,7 @@ ProjectStore::Project::Exists(const std::filesystem::path& BasePath)
 void
 ProjectStore::Project::Read()
 {
-	ZEN_TRACE_CPU("ProjectStore::Project::Read");
+	ZEN_TRACE_CPU("Store::Project::Read");
 
 	using namespace std::literals;
 
@@ -1143,6 +1146,8 @@ ProjectStore::Project::Read()
 void
 ProjectStore::Project::Write()
 {
+	ZEN_TRACE_CPU("Store::Project::Write");
+
 	using namespace std::literals;
 
 	BinaryWriter Mem;
@@ -1297,6 +1302,7 @@ ProjectStore::Project::NewOplog(std::string_view OplogId, const std::filesystem:
 ProjectStore::Oplog*
 ProjectStore::Project::OpenOplog(std::string_view OplogId)
 {
+	ZEN_TRACE_CPU("Store::OpenOplog");
 	{
 		RwLock::SharedLockScope _(m_ProjectLock);
 
@@ -1435,7 +1441,7 @@ ProjectStore::Project::ScrubStorage(ScrubContext& Ctx)
 void
 ProjectStore::Project::GatherReferences(GcContext& GcCtx)
 {
-	ZEN_TRACE_CPU("ProjectStore::Project::GatherReferences");
+	ZEN_TRACE_CPU("Store::Project::GatherReferences");
 
 	Stopwatch  Timer;
 	const auto Guard = MakeGuard([&] {
@@ -1673,7 +1679,7 @@ ProjectStore::ScrubStorage(ScrubContext& Ctx)
 void
 ProjectStore::GatherReferences(GcContext& GcCtx)
 {
-	ZEN_TRACE_CPU("ProjectStore::GatherReferences");
+	ZEN_TRACE_CPU("Store::GatherReferences");
 
 	size_t	   ProjectCount		   = 0;
 	size_t	   ExpiredProjectCount = 0;
@@ -1713,7 +1719,7 @@ ProjectStore::GatherReferences(GcContext& GcCtx)
 void
 ProjectStore::CollectGarbage(GcContext& GcCtx)
 {
-	ZEN_TRACE_CPU("ProjectStore::CollectGarbage");
+	ZEN_TRACE_CPU("Store::CollectGarbage");
 
 	size_t ProjectCount		   = 0;
 	size_t ExpiredProjectCount = 0;
@@ -1816,7 +1822,7 @@ ProjectStore::CollectGarbage(GcContext& GcCtx)
 GcStorageSize
 ProjectStore::StorageSize() const
 {
-	ZEN_TRACE_CPU("ProjectStore::StorageSize");
+	ZEN_TRACE_CPU("Store::StorageSize");
 
 	using namespace std::literals;
 
@@ -1849,7 +1855,7 @@ ProjectStore::StorageSize() const
 Ref<ProjectStore::Project>
 ProjectStore::OpenProject(std::string_view ProjectId)
 {
-	ZEN_TRACE_CPU("ProjectStore::OpenProject");
+	ZEN_TRACE_CPU("Store::OpenProject");
 
 	{
 		RwLock::SharedLockScope _(m_ProjectsLock);
@@ -1898,7 +1904,7 @@ ProjectStore::NewProject(const std::filesystem::path& BasePath,
 						 std::string_view			  ProjectRootDir,
 						 std::string_view			  ProjectFilePath)
 {
-	ZEN_TRACE_CPU("ProjectStore::NewProject");
+	ZEN_TRACE_CPU("Store::NewProject");
 
 	RwLock::ExclusiveLockScope _(m_ProjectsLock);
 
@@ -1922,7 +1928,7 @@ ProjectStore::UpdateProject(std::string_view ProjectId,
 							std::string_view ProjectRootDir,
 							std::string_view ProjectFilePath)
 {
-	ZEN_TRACE_CPU("ProjectStore::UpdateProject");
+	ZEN_TRACE_CPU("Store::UpdateProject");
 
 	ZEN_INFO("updating project {}", ProjectId);
 
@@ -1948,7 +1954,7 @@ ProjectStore::UpdateProject(std::string_view ProjectId,
 bool
 ProjectStore::DeleteProject(std::string_view ProjectId)
 {
-	ZEN_TRACE_CPU("ProjectStore::DeleteProject");
+	ZEN_TRACE_CPU("Store::DeleteProject");
 
 	ZEN_INFO("deleting project {}", ProjectId);
 
@@ -1987,7 +1993,7 @@ ProjectStore::Exists(std::string_view ProjectId)
 CbArray
 ProjectStore::GetProjectsList()
 {
-	ZEN_TRACE_CPU("ProjectStore::GetProjectsList");
+	ZEN_TRACE_CPU("Store::GetProjectsList");
 
 	using namespace std::literals;
 
@@ -2012,7 +2018,7 @@ ProjectStore::GetProjectsList()
 std::pair<HttpResponseCode, std::string>
 ProjectStore::GetProjectFiles(const std::string_view ProjectId, const std::string_view OplogId, bool FilterClient, CbObject& OutPayload)
 {
-	ZEN_TRACE_CPU("ProjectStore::GetProjectFiles");
+	ZEN_TRACE_CPU("Store::GetProjectFiles");
 
 	using namespace std::literals;
 
@@ -2294,7 +2300,7 @@ ProjectStore::PutChunk(const std::string_view ProjectId,
 std::pair<HttpResponseCode, std::string>
 ProjectStore::WriteOplog(const std::string_view ProjectId, const std::string_view OplogId, IoBuffer&& Payload, CbObject& OutResponse)
 {
-	ZEN_TRACE_CPU("ProjectStore::WriteOplog");
+	ZEN_TRACE_CPU("Store::WriteOplog");
 
 	Ref<ProjectStore::Project> Project = OpenProject(ProjectId);
 	if (!Project)
@@ -2366,7 +2372,7 @@ ProjectStore::ReadOplog(const std::string_view				  ProjectId,
 						const HttpServerRequest::QueryParams& Params,
 						CbObject&							  OutResponse)
 {
-	ZEN_TRACE_CPU("ProjectStore::ReadOplog");
+	ZEN_TRACE_CPU("Store::ReadOplog");
 
 	Ref<ProjectStore::Project> Project = OpenProject(ProjectId);
 	if (!Project)
@@ -2420,7 +2426,7 @@ ProjectStore::ReadOplog(const std::string_view				  ProjectId,
 std::pair<HttpResponseCode, std::string>
 ProjectStore::WriteBlock(const std::string_view ProjectId, const std::string_view OplogId, IoBuffer&& Payload)
 {
-	ZEN_TRACE_CPU("ProjectStore::WriteBlock");
+	ZEN_TRACE_CPU("Store::WriteBlock");
 
 	Ref<ProjectStore::Project> Project = OpenProject(ProjectId);
 	if (!Project)
@@ -2455,7 +2461,7 @@ ProjectStore::Rpc(HttpServerRequest&	 HttpReq,
 				  IoBuffer&&			 Payload,
 				  AuthMgr&				 AuthManager)
 {
-	ZEN_TRACE_CPU("ProjectStore::Rpc");
+	ZEN_TRACE_CPU("Store::Rpc");
 
 	using namespace std::literals;
 	HttpContentType PayloadContentType = HttpReq.RequestContentType();
@@ -2550,6 +2556,7 @@ ProjectStore::Rpc(HttpServerRequest&	 HttpReq,
 	}
 	else if (Method == "getchunks"sv)
 	{
+		ZEN_TRACE_CPU("Store::Rpc::getchunks");
 		CbPackage ResponsePackage;
 		{
 			CbArrayView	   ChunksArray = Cb["chunks"sv].AsArrayView();
@@ -2575,6 +2582,7 @@ ProjectStore::Rpc(HttpServerRequest&	 HttpReq,
 	}
 	else if (Method == "putchunks"sv)
 	{
+		ZEN_TRACE_CPU("Store::Rpc::putchunks");
 		if (!AreDiskWritesAllowed())
 		{
 			HttpReq.WriteResponse(HttpResponseCode::InsufficientStorage);
@@ -2592,6 +2600,7 @@ ProjectStore::Rpc(HttpServerRequest&	 HttpReq,
 	}
 	else if (Method == "snapshot"sv)
 	{
+		ZEN_TRACE_CPU("Store::Rpc::snapshot");
 		if (!AreDiskWritesAllowed())
 		{
 			HttpReq.WriteResponse(HttpResponseCode::InsufficientStorage);
@@ -2753,7 +2762,7 @@ ProjectStore::Rpc(HttpServerRequest&	 HttpReq,
 std::pair<HttpResponseCode, std::string>
 ProjectStore::Export(Ref<ProjectStore::Project> Project, ProjectStore::Oplog& Oplog, CbObjectView&& Params, AuthMgr& AuthManager)
 {
-	ZEN_TRACE_CPU("ProjectStore::Export");
+	ZEN_TRACE_CPU("Store::Export");
 
 	using namespace std::literals;
 
@@ -2813,7 +2822,7 @@ ProjectStore::Export(Ref<ProjectStore::Project> Project, ProjectStore::Oplog& Op
 std::pair<HttpResponseCode, std::string>
 ProjectStore::Import(ProjectStore::Project& Project, ProjectStore::Oplog& Oplog, CbObjectView&& Params, AuthMgr& AuthManager)
 {
-	ZEN_TRACE_CPU("ProjectStore::Import");
+	ZEN_TRACE_CPU("Store::Import");
 
 	using namespace std::literals;
 
diff --git a/src/zenstore/blockstore.cpp b/src/zenstore/blockstore.cpp
index cdd7abae7..a16dd4539 100644
--- a/src/zenstore/blockstore.cpp
+++ b/src/zenstore/blockstore.cpp
@@ -66,6 +66,8 @@ BlockStoreFile::Open()
 void
 BlockStoreFile::Create(uint64_t InitialSize)
 {
+	ZEN_TRACE_CPU("BlockStoreFile::Create");
+
 	auto ParentPath = m_Path.parent_path();
 	if (!std::filesystem::is_directory(ParentPath))
 	{
@@ -118,12 +120,14 @@ BlockStoreFile::Read(void* Data, uint64_t Size, uint64_t FileOffset)
 void
 BlockStoreFile::Write(const void* Data, uint64_t Size, uint64_t FileOffset)
 {
+	ZEN_TRACE_CPU("BlockStoreFile::Write");
 	m_File.Write(Data, Size, FileOffset);
 }
 
 void
 BlockStoreFile::Flush()
 {
+	ZEN_TRACE_CPU("BlockStoreFile::Flush");
 	m_File.Flush();
 }
 
@@ -335,6 +339,7 @@ BlockStore::GetReclaimSnapshotState()
 IoBuffer
 BlockStore::TryGetChunk(const BlockStoreLocation& Location) const
 {
+	ZEN_TRACE_CPU("BlockStore::TryGetChunk");
 	RwLock::SharedLockScope InsertLock(m_InsertLock);
 	if (auto BlockIt = m_ChunkBlocks.find(Location.BlockIndex); BlockIt != m_ChunkBlocks.end())
 	{
@@ -499,6 +504,8 @@ BlockStore::ReclaimSpace(const ReclaimSnapshotState&			Snapshot,
 	Ref<BlockStoreFile> NewBlockFile;
 	try
 	{
+		ZEN_TRACE_CPU("BlockStore::ReclaimSpace::Compact");
+
 		uint64_t WriteOffset   = 0;
 		uint32_t NewBlockIndex = 0;
 		for (uint32_t BlockIndex : BlocksToReWrite)
@@ -523,6 +530,8 @@ BlockStore::ReclaimSpace(const ReclaimSnapshotState&			Snapshot,
 			ChunkIndexArray& KeepMap = BlockKeepChunks[ChunkMapIndex];
 			if (KeepMap.empty())
 			{
+				ZEN_TRACE_CPU("BlockStore::ReclaimSpace::DeleteBlock");
+
 				const ChunkIndexArray& DeleteMap = BlockDeleteChunks[ChunkMapIndex];
 				for (size_t DeleteIndex : DeleteMap)
 				{
@@ -561,99 +570,102 @@ BlockStore::ReclaimSpace(const ReclaimSnapshotState&			Snapshot,
 				KeepMap.clear();
 			}
 
-			MovedChunksArray	 MovedChunks;
-			std::vector<uint8_t> Chunk;
-			for (const size_t& ChunkIndex : KeepMap)
+			MovedChunksArray MovedChunks;
 			{
-				const BlockStoreLocation ChunkLocation = ChunkLocations[ChunkIndex];
-				Chunk.resize(ChunkLocation.Size);
-				OldBlockFile->Read(Chunk.data(), Chunk.size(), ChunkLocation.Offset);
-
-				if (!NewBlockFile || (WriteOffset + Chunk.size() > m_MaxBlockSize))
+				ZEN_TRACE_CPU("BlockStore::ReclaimSpace::MoveBlock");
+				std::vector<uint8_t> Chunk;
+				for (const size_t& ChunkIndex : KeepMap)
 				{
-					uint32_t NextBlockIndex = m_WriteBlockIndex.load(std::memory_order_relaxed);
+					const BlockStoreLocation ChunkLocation = ChunkLocations[ChunkIndex];
+					Chunk.resize(ChunkLocation.Size);
+					OldBlockFile->Read(Chunk.data(), Chunk.size(), ChunkLocation.Offset);
 
-					if (NewBlockFile)
+					if (!NewBlockFile || (WriteOffset + Chunk.size() > m_MaxBlockSize))
 					{
-						NewBlockFile->Flush();
-						NewBlockFile = nullptr;
-					}
-					{
-						ChangeCallback(MovedChunks, {});
-						MovedCount += KeepMap.size();
-						MovedChunks.clear();
-						RwLock::ExclusiveLockScope __(m_InsertLock);
-						Stopwatch				   Timer;
-						const auto				   ___ = MakeGuard([&] {
-							uint64_t ElapsedUs = Timer.GetElapsedTimeUs();
-							ReadBlockTimeUs += ElapsedUs;
-							ReadBlockLongestTimeUs = std::max(ElapsedUs, ReadBlockLongestTimeUs);
-						});
-						if (m_ChunkBlocks.size() == m_MaxBlockCount)
-						{
-							ZEN_ERROR("unable to allocate a new block in '{}', count limit {} exeeded",
-									  m_BlocksBasePath,
-									  static_cast<uint64_t>(std::numeric_limits<uint32_t>::max()) + 1);
-							return;
-						}
-						while (m_ChunkBlocks.contains(NextBlockIndex))
+						uint32_t NextBlockIndex = m_WriteBlockIndex.load(std::memory_order_relaxed);
+
+						if (NewBlockFile)
 						{
-							NextBlockIndex = (NextBlockIndex + 1) & (m_MaxBlockCount - 1);
+							NewBlockFile->Flush();
+							NewBlockFile = nullptr;
 						}
-						std::filesystem::path NewBlockPath = GetBlockPath(m_BlocksBasePath, NextBlockIndex);
-						NewBlockFile					   = new BlockStoreFile(NewBlockPath);
-						m_ChunkBlocks[NextBlockIndex]	   = NewBlockFile;
-					}
-
-					std::error_code Error;
-					DiskSpace		Space = DiskSpaceInfo(m_BlocksBasePath, Error);
-					if (Error)
-					{
-						ZEN_ERROR("get disk space in '{}' FAILED, reason: '{}'", m_BlocksBasePath, Error.message());
-						return;
-					}
-					if (Space.Free < m_MaxBlockSize)
-					{
-						uint64_t ReclaimedSpace = DiskReserveCallback();
-						if (Space.Free + ReclaimedSpace < m_MaxBlockSize)
 						{
-							ZEN_WARN("garbage collect for '{}' FAILED, required disk space {}, free {}",
-									 m_BlocksBasePath,
-									 m_MaxBlockSize,
-									 NiceBytes(Space.Free + ReclaimedSpace));
-							RwLock::ExclusiveLockScope _l(m_InsertLock);
+							ChangeCallback(MovedChunks, {});
+							MovedCount += KeepMap.size();
+							MovedChunks.clear();
+							RwLock::ExclusiveLockScope __(m_InsertLock);
 							Stopwatch				   Timer;
-							const auto				   __ = MakeGuard([&] {
+							const auto				   ___ = MakeGuard([&] {
 								uint64_t ElapsedUs = Timer.GetElapsedTimeUs();
 								ReadBlockTimeUs += ElapsedUs;
 								ReadBlockLongestTimeUs = std::max(ElapsedUs, ReadBlockLongestTimeUs);
 							});
-							ZEN_ASSERT(m_ChunkBlocks[NextBlockIndex] == NewBlockFile);
-							m_ChunkBlocks.erase(NextBlockIndex);
-							NewBlockFile->MarkAsDeleteOnClose();
-							return;
+							if (m_ChunkBlocks.size() == m_MaxBlockCount)
+							{
+								ZEN_ERROR("unable to allocate a new block in '{}', count limit {} exeeded",
+										  m_BlocksBasePath,
+										  static_cast<uint64_t>(std::numeric_limits<uint32_t>::max()) + 1);
+								return;
+							}
+							while (m_ChunkBlocks.contains(NextBlockIndex))
+							{
+								NextBlockIndex = (NextBlockIndex + 1) & (m_MaxBlockCount - 1);
+							}
+							std::filesystem::path NewBlockPath = GetBlockPath(m_BlocksBasePath, NextBlockIndex);
+							NewBlockFile					   = new BlockStoreFile(NewBlockPath);
+							m_ChunkBlocks[NextBlockIndex]	   = NewBlockFile;
 						}
 
-						ZEN_INFO("using gc reserve for '{}', reclaimed {}, disk free {}",
-								 m_BlocksBasePath,
-								 ReclaimedSpace,
-								 NiceBytes(Space.Free + ReclaimedSpace));
+						std::error_code Error;
+						DiskSpace		Space = DiskSpaceInfo(m_BlocksBasePath, Error);
+						if (Error)
+						{
+							ZEN_ERROR("get disk space in '{}' FAILED, reason: '{}'", m_BlocksBasePath, Error.message());
+							return;
+						}
+						if (Space.Free < m_MaxBlockSize)
+						{
+							uint64_t ReclaimedSpace = DiskReserveCallback();
+							if (Space.Free + ReclaimedSpace < m_MaxBlockSize)
+							{
+								ZEN_WARN("garbage collect for '{}' FAILED, required disk space {}, free {}",
+										 m_BlocksBasePath,
+										 m_MaxBlockSize,
+										 NiceBytes(Space.Free + ReclaimedSpace));
+								RwLock::ExclusiveLockScope _l(m_InsertLock);
+								Stopwatch				   Timer;
+								const auto				   __ = MakeGuard([&] {
+									uint64_t ElapsedUs = Timer.GetElapsedTimeUs();
+									ReadBlockTimeUs += ElapsedUs;
+									ReadBlockLongestTimeUs = std::max(ElapsedUs, ReadBlockLongestTimeUs);
+								});
+								ZEN_ASSERT(m_ChunkBlocks[NextBlockIndex] == NewBlockFile);
+								m_ChunkBlocks.erase(NextBlockIndex);
+								NewBlockFile->MarkAsDeleteOnClose();
+								return;
+							}
+
+							ZEN_INFO("using gc reserve for '{}', reclaimed {}, disk free {}",
+									 m_BlocksBasePath,
+									 ReclaimedSpace,
+									 NiceBytes(Space.Free + ReclaimedSpace));
+						}
+						NewBlockFile->Create(m_MaxBlockSize);
+						NewBlockIndex = NextBlockIndex;
+						WriteOffset	  = 0;
 					}
-					NewBlockFile->Create(m_MaxBlockSize);
-					NewBlockIndex = NextBlockIndex;
-					WriteOffset	  = 0;
-				}
 
-				NewBlockFile->Write(Chunk.data(), Chunk.size(), WriteOffset);
-				MovedChunks.push_back({ChunkIndex, {.BlockIndex = NewBlockIndex, .Offset = WriteOffset, .Size = Chunk.size()}});
-				uint64_t OldOffset = WriteOffset;
-				WriteOffset		   = RoundUp(WriteOffset + Chunk.size(), PayloadAlignment);
-				m_TotalSize.fetch_add(WriteOffset - OldOffset, std::memory_order::relaxed);
-			}
-			Chunk.clear();
-			if (NewBlockFile)
-			{
-				NewBlockFile->Flush();
+					NewBlockFile->Write(Chunk.data(), Chunk.size(), WriteOffset);
+					MovedChunks.push_back({ChunkIndex, {.BlockIndex = NewBlockIndex, .Offset = WriteOffset, .Size = Chunk.size()}});
+					uint64_t OldOffset = WriteOffset;
+					WriteOffset		   = RoundUp(WriteOffset + Chunk.size(), PayloadAlignment);
+					m_TotalSize.fetch_add(WriteOffset - OldOffset, std::memory_order::relaxed);
+				}
+				Chunk.clear();
+				if (NewBlockFile)
+				{
+					NewBlockFile->Flush();
+				}
 			}
 
 			const ChunkIndexArray& DeleteMap = BlockDeleteChunks[ChunkMapIndex];
diff --git a/src/zenstore/cas.cpp b/src/zenstore/cas.cpp
index b98f01385..9446e2152 100644
--- a/src/zenstore/cas.cpp
+++ b/src/zenstore/cas.cpp
@@ -243,6 +243,8 @@ CasImpl::FindChunk(const IoHash& ChunkHash)
 bool
 CasImpl::ContainsChunk(const IoHash& ChunkHash)
 {
+	ZEN_TRACE_CPU("CAS::ContainsChunk");
+
 	return m_SmallStrategy.HaveChunk(ChunkHash) || m_TinyStrategy.HaveChunk(ChunkHash) || m_LargeStrategy.HaveChunk(ChunkHash);
 }
 
diff --git a/src/zenstore/compactcas.cpp b/src/zenstore/compactcas.cpp
index fe31ad759..63158f6de 100644
--- a/src/zenstore/compactcas.cpp
+++ b/src/zenstore/compactcas.cpp
@@ -147,6 +147,7 @@ CasContainerStrategy::Initialize(const std::filesystem::path& RootDirectory,
 CasStore::InsertResult
 CasContainerStrategy::InsertChunk(const void* ChunkData, size_t ChunkSize, const IoHash& ChunkHash)
 {
+	ZEN_TRACE_CPU("CasContainer::InsertChunk");
 	{
 		RwLock::SharedLockScope _(m_LocationMapLock);
 		if (m_LocationMap.contains(ChunkHash))
@@ -192,6 +193,8 @@ CasContainerStrategy::InsertChunk(IoBuffer Chunk, const IoHash& ChunkHash)
 IoBuffer
 CasContainerStrategy::FindChunk(const IoHash& ChunkHash)
 {
+	ZEN_TRACE_CPU("CasContainer::FindChunk");
+
 	RwLock::SharedLockScope _(m_LocationMapLock);
 	auto					KeyIt = m_LocationMap.find(ChunkHash);
 	if (KeyIt == m_LocationMap.end())
@@ -418,6 +421,8 @@ CasContainerStrategy::CollectGarbage(GcContext& GcCtx)
 	LocationMap_t					 LocationMap;
 	BlockStore::ReclaimSnapshotState BlockStoreState;
 	{
+		ZEN_TRACE_CPU("CasContainer::CollectGarbage::State");
+
 		RwLock::SharedLockScope ___(m_LocationMapLock);
 		Stopwatch				Timer;
 		const auto				____ = MakeGuard([&Timer, &WriteBlockTimeUs, &WriteBlockLongestTimeUs] {
@@ -445,19 +450,22 @@ CasContainerStrategy::CollectGarbage(GcContext& GcCtx)
 	KeepChunkIndexes.reserve(TotalChunkCount);
 	ChunkIndexToChunkHash.reserve(TotalChunkCount);
 
-	GcCtx.FilterCids(TotalChunkHashes, [&](const IoHash& ChunkHash, bool Keep) {
-		auto						  KeyIt		   = LocationMap.find(ChunkHash);
-		const BlockStoreDiskLocation& DiskLocation = KeyIt->second;
-		BlockStoreLocation			  Location	   = DiskLocation.Get(m_PayloadAlignment);
-		size_t						  ChunkIndex   = ChunkLocations.size();
-
-		ChunkLocations.push_back(Location);
-		ChunkIndexToChunkHash[ChunkIndex] = ChunkHash;
-		if (Keep)
-		{
-			KeepChunkIndexes.push_back(ChunkIndex);
-		}
-	});
+	{
+		ZEN_TRACE_CPU("CasContainer::CollectGarbage::Filter");
+		GcCtx.FilterCids(TotalChunkHashes, [&](const IoHash& ChunkHash, bool Keep) {
+			auto						  KeyIt		   = LocationMap.find(ChunkHash);
+			const BlockStoreDiskLocation& DiskLocation = KeyIt->second;
+			BlockStoreLocation			  Location	   = DiskLocation.Get(m_PayloadAlignment);
+			size_t						  ChunkIndex   = ChunkLocations.size();
+
+			ChunkLocations.push_back(Location);
+			ChunkIndexToChunkHash[ChunkIndex] = ChunkHash;
+			if (Keep)
+			{
+				KeepChunkIndexes.push_back(ChunkIndex);
+			}
+		});
+	}
 
 	const bool PerformDelete = GcCtx.IsDeletionMode() && GcCtx.CollectSmallObjects();
 	if (!PerformDelete)
diff --git a/src/zenstore/filecas.cpp b/src/zenstore/filecas.cpp
index 56a840701..ce0dd7ce6 100644
--- a/src/zenstore/filecas.cpp
+++ b/src/zenstore/filecas.cpp
@@ -241,7 +241,7 @@ FileCasStrategy::InsertChunk(IoBuffer Chunk, const IoHash& ChunkHash, CasStore::
 				return CasStore::InsertResult{.New = false};
 			}
 		}
-		return InsertChunk(Chunk.Data(), Chunk.Size(), ChunkHash);
+		return InsertChunkData(Chunk.Data(), Chunk.Size(), ChunkHash);
 	}
 
 	// File-based chunks have special case handling whereby we move the file into
@@ -251,6 +251,8 @@ FileCasStrategy::InsertChunk(IoBuffer Chunk, const IoHash& ChunkHash, CasStore::
 	bool				  IsWholeFile = Chunk.IsWholeFile();
 	if (IsWholeFile && Chunk.GetFileReference(/* out */ FileRef))
 	{
+		ZEN_TRACE_CPU("FileCas::InsertChunk::Move");
+
 		{
 			bool Exists = true;
 			{
@@ -271,6 +273,8 @@ FileCasStrategy::InsertChunk(IoBuffer Chunk, const IoHash& ChunkHash, CasStore::
 		const HANDLE ChunkFileHandle = FileRef.FileHandle;
 		// See if file already exists
 		{
+			ZEN_TRACE_CPU("FileCas::InsertChunk::Exists");
+
 			windows::FileHandle PayloadFile;
 
 			if (HRESULT hRes = PayloadFile.Create(Name.ShardedPath.c_str(), GENERIC_READ, FILE_SHARE_READ, OPEN_EXISTING); SUCCEEDED(hRes))
@@ -486,11 +490,11 @@ FileCasStrategy::InsertChunk(IoBuffer Chunk, const IoHash& ChunkHash, CasStore::
 #endif	// ZEN_PLATFORM_*
 	}
 
-	return InsertChunk(Chunk.Data(), Chunk.Size(), ChunkHash);
+	return InsertChunkData(Chunk.Data(), Chunk.Size(), ChunkHash);
 }
 
 CasStore::InsertResult
-FileCasStrategy::InsertChunk(const void* const ChunkData, const size_t ChunkSize, const IoHash& ChunkHash)
+FileCasStrategy::InsertChunkData(const void* const ChunkData, const size_t ChunkSize, const IoHash& ChunkHash)
 {
 	ZEN_TRACE_CPU("FileCas::InsertChunkData");
 
@@ -504,6 +508,8 @@ FileCasStrategy::InsertChunk(const void* const ChunkData, const size_t ChunkSize
 		}
 	}
 
+	ZEN_TRACE_CPU("FileCas::InsertChunkData::Write");
+
 	ShardingHelper Name(m_RootDirectory.c_str(), ChunkHash);
 
 	// See if file already exists
@@ -696,6 +702,8 @@ FileCasStrategy::InsertChunk(const void* const ChunkData, const size_t ChunkSize
 IoBuffer
 FileCasStrategy::FindChunk(const IoHash& ChunkHash)
 {
+	ZEN_TRACE_CPU("FileCas::FindChunk");
+
 	ZEN_ASSERT(m_IsInitialized);
 
 	{
@@ -706,8 +714,6 @@ FileCasStrategy::FindChunk(const IoHash& ChunkHash)
 		}
 	}
 
-	ZEN_TRACE_CPU("FileCas::FindChunk");
-
 	ShardingHelper Name(m_RootDirectory.c_str(), ChunkHash);
 
 	RwLock::SharedLockScope _(LockForHash(ChunkHash));
@@ -914,25 +920,28 @@ FileCasStrategy::CollectGarbage(GcContext& GcCtx)
 				  NiceBytes(OldTotalSize));
 	});
 
-	IterateChunks([&](const IoHash& Hash, IoBuffer&& Payload) {
-		bool KeepThis	= false;
-		CandidateCas[0] = Hash;
-		GcCtx.FilterCids(CandidateCas, [&](const IoHash& Hash) {
-			ZEN_UNUSED(Hash);
-			KeepThis = true;
-		});
-
-		const uint64_t FileSize = Payload.GetSize();
-
-		if (!KeepThis)
-		{
-			ChunksToDelete.push_back(Hash);
-			ChunksToDeleteBytes.fetch_add(FileSize);
-		}
+	{
+		ZEN_TRACE_CPU("FileCas::CollectGarbage::Filter");
+		IterateChunks([&](const IoHash& Hash, IoBuffer&& Payload) {
+			bool KeepThis	= false;
+			CandidateCas[0] = Hash;
+			GcCtx.FilterCids(CandidateCas, [&](const IoHash& Hash) {
+				ZEN_UNUSED(Hash);
+				KeepThis = true;
+			});
+
+			const uint64_t FileSize = Payload.GetSize();
+
+			if (!KeepThis)
+			{
+				ChunksToDelete.push_back(Hash);
+				ChunksToDeleteBytes.fetch_add(FileSize);
+			}
 
-		++ChunkCount;
-		ChunkBytes.fetch_add(FileSize);
-	});
+			++ChunkCount;
+			ChunkBytes.fetch_add(FileSize);
+		});
+	}
 
 	// TODO, any entires we did not encounter during our IterateChunks should be removed from the index
 
diff --git a/src/zenstore/filecas.h b/src/zenstore/filecas.h
index e4eab183a..d9186f05b 100644
--- a/src/zenstore/filecas.h
+++ b/src/zenstore/filecas.h
@@ -55,7 +55,7 @@ private:
 	};
 	using IndexMap = tsl::robin_map<IoHash, IndexEntry, IoHash::Hasher>;
 
-	CasStore::InsertResult InsertChunk(const void* ChunkData, size_t ChunkSize, const IoHash& ChunkHash);
+	CasStore::InsertResult InsertChunkData(const void* ChunkData, size_t ChunkSize, const IoHash& ChunkHash);
 
 	std::filesystem::path m_RootDirectory;
 	RwLock				  m_Lock;
diff --git a/src/zenstore/gc.cpp b/src/zenstore/gc.cpp
index 79aea2752..a3282dde6 100644
--- a/src/zenstore/gc.cpp
+++ b/src/zenstore/gc.cpp
@@ -399,6 +399,7 @@ GcManager::CollectGarbage(GcContext& GcCtx)
 
 	// First gather reference set
 	{
+		ZEN_TRACE_CPU("Gc::CollectGarbage::GatherReferences");
 		Stopwatch  Timer;
 		const auto Guard = MakeGuard([&] { ZEN_INFO("gathered references in {}", NiceTimeSpanMs(Timer.GetElapsedTimeMs())); });
 		for (GcContributor* Contributor : m_GcContribs)
@@ -409,6 +410,8 @@ GcManager::CollectGarbage(GcContext& GcCtx)
 
 	// Then trim storage
 	{
+		ZEN_TRACE_CPU("Gc::CollectGarbage::CollectGarbage");
+
 		GcStorageSize GCTotalSizeDiff;
 		Stopwatch	  Timer;
 		const auto	  Guard = MakeGuard([&] {
@@ -989,6 +992,8 @@ GcScheduler::CollectGarbage(const GcClock::TimePoint& CacheExpireTime,
 							bool					  Delete,
 							bool					  CollectSmallObjects)
 {
+	ZEN_TRACE_CPU("GcScheduler::CollectGarbage");
+
 	GcContext GcCtx(CacheExpireTime, ProjectStoreExpireTime);
 	GcCtx.SetDeletionMode(Delete);
 	GcCtx.CollectSmallObjects(CollectSmallObjects);