Added trace scopes.

7 files changed, 86 insertions, 4 deletions

diff --git a/zenserver/cache/structuredcache.cpp b/zenserver/cache/structuredcache.cpp
index ebf6298a4..47ac9f6e7 100644
--- a/zenserver/cache/structuredcache.cpp
+++ b/zenserver/cache/structuredcache.cpp
@@ -7,6 +7,7 @@
 #include <zencore/compactbinarypackage.h>
 #include <zencore/compactbinaryvalidation.h>
 #include <zencore/compress.h>
+#include <zencore/trace.h>
 #include <zencore/fmtutils.h>
 #include <zencore/logging.h>
 #include <zencore/scopeguard.h>
@@ -810,6 +811,8 @@ HttpStructuredCacheService::HandleRpcRequest(zen::HttpServerRequest& Request)
 void
 HttpStructuredCacheService::HandleRpcGetCacheRecords(zen::HttpServerRequest& Request, CbObjectView RpcRequest)
 {
+	ZEN_TRACE_CPU("Z$::RpcGetCacheRecords");
+
 	using namespace fmt::literals;
 
 	CbPackage			  RpcResponse;
@@ -1006,6 +1009,8 @@ HttpStructuredCacheService::HandleRpcGetCacheRecords(zen::HttpServerRequest& Req
 void
 HttpStructuredCacheService::HandleRpcGetCachePayloads(zen::HttpServerRequest& Request, CbObjectView RpcRequest)
 {
+	ZEN_TRACE_CPU("Z$::RpcGetCachePayloads");
+
 	using namespace fmt::literals;
 
 	ZEN_ASSERT(RpcRequest["Method"sv].AsString() == "GetCachePayloads"sv);
diff --git a/zenserver/cache/structuredcachestore.cpp b/zenserver/cache/structuredcachestore.cpp
index 8f1754346..a1a30e4af 100644
--- a/zenserver/cache/structuredcachestore.cpp
+++ b/zenserver/cache/structuredcachestore.cpp
@@ -18,6 +18,7 @@
 #include <zencore/testutils.h>
 #include <zencore/thread.h>
 #include <zencore/timer.h>
+#include <zencore/trace.h>
 #include <zenstore/cidstore.h>
 
 #if ZEN_PLATFORM_WINDOWS
@@ -82,6 +83,8 @@ ZenCacheStore::~ZenCacheStore()
 bool
 ZenCacheStore::Get(std::string_view InBucket, const IoHash& HashKey, ZenCacheValue& OutValue)
 {
+	ZEN_TRACE_CPU("Z$::Get");
+
 	bool Ok = m_MemLayer.Get(InBucket, HashKey, OutValue);
 
 #if ZEN_USE_CACHE_TRACKER
@@ -118,6 +121,8 @@ ZenCacheStore::Get(std::string_view InBucket, const IoHash& HashKey, ZenCacheVal
 void
 ZenCacheStore::Put(std::string_view InBucket, const IoHash& HashKey, const ZenCacheValue& Value)
 {
+	ZEN_TRACE_CPU("Z$::Put");
+
 	// Store value and index
 
 	ZEN_ASSERT(Value.Value.Size());
@@ -745,6 +750,8 @@ ZenCacheDiskLayer::CacheBucket::Scrub(ScrubContext& Ctx)
 void
 ZenCacheDiskLayer::CacheBucket::GatherReferences(GcContext& GcCtx)
 {
+	ZEN_TRACE_CPU("Z$::DiskLayer::CacheBucket::GatherReferences");
+
 	const GcClock::TimePoint ExpireTime =
 		GcCtx.MaxCacheDuration() == GcClock::Duration::max() ? GcClock::TimePoint::min() : GcCtx.Time() - GcCtx.MaxCacheDuration();
 
@@ -805,6 +812,8 @@ ZenCacheDiskLayer::CacheBucket::GatherReferences(GcContext& GcCtx)
 void
 ZenCacheDiskLayer::CacheBucket::CollectGarbage(GcContext& GcCtx)
 {
+	ZEN_TRACE_CPU("Z$::DiskLayer::CacheBucket::CollectGarbage");
+
 	Flush();
 
 	RwLock::ExclusiveLockScope _(m_IndexLock);
diff --git a/zenserver/config.h b/zenserver/config.h
index 60e9976e0..023e297c9 100644
--- a/zenserver/config.h
+++ b/zenserver/config.h
@@ -19,10 +19,6 @@
 #	define ZEN_USE_EXEC 0
 #endif
 
-#ifndef ZEN_WITH_TRACE
-#	define ZEN_WITH_TRACE 0
-#endif
-
 struct ZenUpstreamJupiterConfig
 {
 	std::string Url;
diff --git a/zenserver/projectstore.cpp b/zenserver/projectstore.cpp
index 82dac08cd..4f9897e07 100644
--- a/zenserver/projectstore.cpp
+++ b/zenserver/projectstore.cpp
@@ -13,6 +13,7 @@
 #include <zencore/testing.h>
 #include <zencore/testutils.h>
 #include <zencore/timer.h>
+#include <zencore/trace.h>
 #include <zenstore/basicfile.h>
 #include <zenstore/cas.h>
 #include <zenstore/caslog.h>
@@ -170,6 +171,8 @@ struct ProjectStore::OplogStorage : public RefCounted
 
 	void ReplayLog(std::function<void(CbObject, const OplogEntry&)>&& Handler)
 	{
+		ZEN_TRACE_CPU("ProjectStore::OplogStorage::ReplayLog");
+
 		// This could use memory mapping or do something clever but for now it just reads the file sequentially
 
 		ZEN_INFO("replaying log for '{}'", m_OplogStoragePath);
@@ -241,6 +244,8 @@ struct ProjectStore::OplogStorage : public RefCounted
 
 	OplogEntry AppendOp(CbObject Op)
 	{
+		ZEN_TRACE_CPU("ProjectStore::OplogStorage::AppendOp");
+
 		SharedBuffer   Buffer	  = Op.GetBuffer();
 		const uint64_t WriteSize  = Buffer.GetSize();
 		const auto	   OpCoreHash = uint32_t(XXH3_64bits(Buffer.GetData(), WriteSize) & 0xffffFFFF);
@@ -500,6 +505,8 @@ ProjectStore::Oplog::AddMetaMapping(Oid ChunkId, IoHash Hash)
 uint32_t
 ProjectStore::Oplog::RegisterOplogEntry(CbObject Core, const OplogEntry& OpEntry, UpdateType TypeOfUpdate)
 {
+	ZEN_TRACE_CPU("ProjectStore::Oplog::RegisterOplogEntry");
+
 	ZEN_UNUSED(TypeOfUpdate);
 
 	// For now we're assuming the update is all in-memory so we can hold an exclusive lock without causing
@@ -581,6 +588,8 @@ ProjectStore::Oplog::RegisterOplogEntry(CbObject Core, const OplogEntry& OpEntry
 uint32_t
 ProjectStore::Oplog::AppendNewOplogEntry(CbPackage OpPackage)
 {
+	ZEN_TRACE_CPU("ProjectStore::Oplog::AppendNewOplogEntry");
+
 	using namespace std::literals;
 
 	const CbObject&	 Core	 = OpPackage.GetObject();
diff --git a/zenserver/upstream/jupiter.cpp b/zenserver/upstream/jupiter.cpp
index 177184591..ffb9b1cbf 100644
--- a/zenserver/upstream/jupiter.cpp
+++ b/zenserver/upstream/jupiter.cpp
@@ -10,6 +10,7 @@
 #include <zencore/iohash.h>
 #include <zencore/string.h>
 #include <zencore/thread.h>
+#include <zencore/trace.h>
 
 ZEN_THIRD_PARTY_INCLUDES_START
 #include <cpr/cpr.h>
@@ -86,6 +87,8 @@ CloudCacheSession::Authenticate()
 CloudCacheResult
 CloudCacheSession::GetDerivedData(std::string_view BucketId, std::string_view Key)
 {
+	ZEN_TRACE_CPU("HordeClient::GetDerivedData");
+
 	const CloudCacheAccessToken& AccessToken = GetAccessToken();
 	if (!AccessToken.IsValid())
 	{
@@ -203,6 +206,8 @@ CloudCacheSession::GetBlob(const IoHash& Key)
 CloudCacheResult
 CloudCacheSession::GetCompressedBlob(const IoHash& Key)
 {
+	ZEN_TRACE_CPU("HordeClient::GetCompressedBlob");
+
 	const CloudCacheAccessToken& AccessToken = GetAccessToken();
 	if (!AccessToken.IsValid())
 	{
@@ -239,6 +244,8 @@ CloudCacheSession::GetCompressedBlob(const IoHash& Key)
 CloudCacheResult
 CloudCacheSession::GetObject(const IoHash& Key)
 {
+	ZEN_TRACE_CPU("HordeClient::GetObject");
+
 	const CloudCacheAccessToken& AccessToken = GetAccessToken();
 	if (!AccessToken.IsValid())
 	{
@@ -275,6 +282,8 @@ CloudCacheSession::GetObject(const IoHash& Key)
 CloudCacheResult
 CloudCacheSession::PutDerivedData(std::string_view BucketId, std::string_view Key, IoBuffer DerivedData)
 {
+	ZEN_TRACE_CPU("HordeClient::PutDerivedData");
+
 	const CloudCacheAccessToken& AccessToken = GetAccessToken();
 	if (!AccessToken.IsValid())
 	{
@@ -320,6 +329,8 @@ CloudCacheSession::PutDerivedData(std::string_view BucketId, const IoHash& Key,
 PutRefResult
 CloudCacheSession::PutRef(std::string_view BucketId, const IoHash& Key, IoBuffer Ref, ZenContentType RefType)
 {
+	ZEN_TRACE_CPU("HordeClient::PutRef");
+
 	const CloudCacheAccessToken& AccessToken = GetAccessToken();
 	if (!AccessToken.IsValid())
 	{
@@ -387,6 +398,8 @@ CloudCacheSession::PutRef(std::string_view BucketId, const IoHash& Key, IoBuffer
 FinalizeRefResult
 CloudCacheSession::FinalizeRef(std::string_view BucketId, const IoHash& Key, const IoHash& RefHash)
 {
+	ZEN_TRACE_CPU("HordeClient::FinalizeRef");
+
 	const CloudCacheAccessToken& AccessToken = GetAccessToken();
 	if (!AccessToken.IsValid())
 	{
@@ -451,6 +464,8 @@ CloudCacheSession::FinalizeRef(std::string_view BucketId, const IoHash& Key, con
 CloudCacheResult
 CloudCacheSession::PutBlob(const IoHash& Key, IoBuffer Blob)
 {
+	ZEN_TRACE_CPU("HordeClient::PutBlob");
+
 	const CloudCacheAccessToken& AccessToken = GetAccessToken();
 	if (!AccessToken.IsValid())
 	{
@@ -486,6 +501,8 @@ CloudCacheSession::PutBlob(const IoHash& Key, IoBuffer Blob)
 CloudCacheResult
 CloudCacheSession::PutCompressedBlob(const IoHash& Key, IoBuffer Blob)
 {
+	ZEN_TRACE_CPU("HordeClient::PutCompressedBlob");
+
 	const CloudCacheAccessToken& AccessToken = GetAccessToken();
 	if (!AccessToken.IsValid())
 	{
@@ -521,6 +538,8 @@ CloudCacheSession::PutCompressedBlob(const IoHash& Key, IoBuffer Blob)
 CloudCacheResult
 CloudCacheSession::PutObject(const IoHash& Key, IoBuffer Object)
 {
+	ZEN_TRACE_CPU("HordeClient::PutObject");
+
 	const CloudCacheAccessToken& AccessToken = GetAccessToken();
 	if (!AccessToken.IsValid())
 	{
@@ -556,6 +575,8 @@ CloudCacheSession::PutObject(const IoHash& Key, IoBuffer Object)
 CloudCacheResult
 CloudCacheSession::RefExists(std::string_view BucketId, const IoHash& Key)
 {
+	ZEN_TRACE_CPU("HordeClient::RefExists");
+
 	const CloudCacheAccessToken& AccessToken = GetAccessToken();
 	if (!AccessToken.IsValid())
 	{
@@ -626,6 +647,8 @@ CloudCacheSession::ObjectExists(const std::set<IoHash>& Keys)
 CloudCacheResult
 CloudCacheSession::PostComputeTasks(std::string_view ChannelId, IoBuffer TasksData)
 {
+	ZEN_TRACE_CPU("HordeClient::PostComputeTasks");
+
 	const CloudCacheAccessToken& AccessToken = GetAccessToken();
 	if (!AccessToken.IsValid())
 	{
@@ -695,6 +718,8 @@ CloudCacheSession::GetComputeUpdates(std::string_view ChannelId, const uint32_t
 CloudCacheResult
 CloudCacheSession::GetObjectTree(const IoHash& Key)
 {
+	ZEN_TRACE_CPU("HordeClient::GetObjectTree");
+
 	const CloudCacheAccessToken& AccessToken = GetAccessToken();
 	if (!AccessToken.IsValid())
 	{
@@ -919,6 +944,8 @@ CloudCacheClient::~CloudCacheClient()
 CloudCacheAccessToken
 CloudCacheClient::AcquireAccessToken()
 {
+	ZEN_TRACE_CPU("HordeClient::AcquireAccessToken");
+
 	using namespace std::chrono;
 
 	// If an access token was provided, return it instead of querying OAuth
diff --git a/zenserver/upstream/upstreamcache.cpp b/zenserver/upstream/upstreamcache.cpp
index 6283457e3..38179f490 100644
--- a/zenserver/upstream/upstreamcache.cpp
+++ b/zenserver/upstream/upstreamcache.cpp
@@ -13,6 +13,7 @@
 #include <zencore/stats.h>
 #include <zencore/stream.h>
 #include <zencore/timer.h>
+#include <zencore/trace.h>
 
 #include <zenstore/cas.h>
 #include <zenstore/cidstore.h>
@@ -72,6 +73,8 @@ namespace detail {
 
 		virtual GetUpstreamCacheResult GetCacheRecord(CacheKey CacheKey, ZenContentType Type) override
 		{
+			ZEN_TRACE_CPU("Upstream::Horde::GetSingleCacheRecord");
+
 			try
 			{
 				CloudCacheSession Session(m_Client);
@@ -149,6 +152,8 @@ namespace detail {
 													   const CacheRecordPolicy&	  Policy,
 													   OnCacheRecordGetComplete&& OnComplete) override
 		{
+			ZEN_TRACE_CPU("Upstream::Horde::GetCacheRecords");
+
 			ZEN_UNUSED(Policy);
 
 			CloudCacheSession	   Session(m_Client);
@@ -203,6 +208,8 @@ namespace detail {
 
 		virtual GetUpstreamCacheResult GetCachePayload(const CacheKey&, const IoHash& PayloadId) override
 		{
+			ZEN_TRACE_CPU("Upstream::Horde::GetSingleCachePayload");
+
 			try
 			{
 				CloudCacheSession	   Session(m_Client);
@@ -232,6 +239,8 @@ namespace detail {
 														std::span<size_t>			 RequestIndex,
 														OnCachePayloadGetComplete&&	 OnComplete) override final
 		{
+			ZEN_TRACE_CPU("Upstream::Horde::GetCachePayloads");
+
 			CloudCacheSession	   Session(m_Client);
 			GetUpstreamCacheResult Result;
 
@@ -259,6 +268,8 @@ namespace detail {
 													  IoBuffer					 RecordValue,
 													  std::span<IoBuffer const>	 Payloads) override
 		{
+			ZEN_TRACE_CPU("Upstream::Horde::PutCacheRecord");
+
 			using namespace fmt::literals;
 
 			ZEN_ASSERT(CacheRecord.PayloadIds.size() == Payloads.size());
@@ -529,6 +540,8 @@ namespace detail {
 
 		virtual GetUpstreamCacheResult GetCacheRecord(CacheKey CacheKey, ZenContentType Type) override
 		{
+			ZEN_TRACE_CPU("Upstream::Zen::GetSingleCacheRecord");
+
 			try
 			{
 				ZenStructuredCacheSession Session(*m_Client);
@@ -559,6 +572,8 @@ namespace detail {
 													   const CacheRecordPolicy&	  Policy,
 													   OnCacheRecordGetComplete&& OnComplete) override
 		{
+			ZEN_TRACE_CPU("Upstream::Zen::GetCacheRecords");
+
 			std::vector<size_t> IndexMap;
 			IndexMap.reserve(KeyIndex.size());
 
@@ -623,6 +638,8 @@ namespace detail {
 
 		virtual GetUpstreamCacheResult GetCachePayload(const CacheKey& CacheKey, const IoHash& PayloadId) override
 		{
+			ZEN_TRACE_CPU("Upstream::Zen::GetSingleCachePayload");
+
 			try
 			{
 				ZenStructuredCacheSession Session(*m_Client);
@@ -652,6 +669,8 @@ namespace detail {
 														std::span<size_t>			 RequestIndex,
 														OnCachePayloadGetComplete&&	 OnComplete) override final
 		{
+			ZEN_TRACE_CPU("Upstream::Zen::GetCachePayloads");
+
 			std::vector<size_t> IndexMap;
 			IndexMap.reserve(RequestIndex.size());
 
@@ -736,6 +755,8 @@ namespace detail {
 													  IoBuffer					 RecordValue,
 													  std::span<IoBuffer const>	 Payloads) override
 		{
+			ZEN_TRACE_CPU("Upstream::Zen::PutCacheRecord");
+
 			ZEN_ASSERT(CacheRecord.PayloadIds.size() == Payloads.size());
 			const int32_t MaxAttempts = 3;
 
@@ -1020,6 +1041,8 @@ public:
 
 	virtual GetUpstreamCacheResult GetCacheRecord(CacheKey CacheKey, ZenContentType Type) override
 	{
+		ZEN_TRACE_CPU("Upstream::GetCacheRecord");
+
 		if (m_Options.ReadUpstream)
 		{
 			for (auto& Endpoint : m_Endpoints)
@@ -1053,6 +1076,8 @@ public:
 								 const CacheRecordPolicy&	Policy,
 								 OnCacheRecordGetComplete&& OnComplete) override final
 	{
+		ZEN_TRACE_CPU("Upstream::GetCacheRecords");
+
 		std::vector<size_t> MissingKeys(KeyIndex.begin(), KeyIndex.end());
 
 		if (m_Options.ReadUpstream)
@@ -1098,6 +1123,8 @@ public:
 								  std::span<size_t>			   RequestIndex,
 								  OnCachePayloadGetComplete&&  OnComplete) override final
 	{
+		ZEN_TRACE_CPU("Upstream::GetCachePayloads");
+
 		std::vector<size_t> MissingPayloads(RequestIndex.begin(), RequestIndex.end());
 
 		if (m_Options.ReadUpstream)
@@ -1142,6 +1169,8 @@ public:
 
 	virtual GetUpstreamCacheResult GetCachePayload(const CacheKey& CacheKey, const IoHash& PayloadId) override
 	{
+		ZEN_TRACE_CPU("Upstream::GetCachePayload");
+
 		if (m_Options.ReadUpstream)
 		{
 			for (auto& Endpoint : m_Endpoints)
@@ -1224,6 +1253,8 @@ public:
 private:
 	void ProcessCacheRecord(UpstreamCacheRecord CacheRecord)
 	{
+		ZEN_TRACE_CPU("Upstream::ProcessCacheRecord");
+
 		ZenCacheValue		  CacheValue;
 		std::vector<IoBuffer> Payloads;
 
diff --git a/zenstore/cas.cpp b/zenstore/cas.cpp
index d4023bdc4..1fd01ff0c 100644
--- a/zenstore/cas.cpp
+++ b/zenstore/cas.cpp
@@ -16,6 +16,7 @@
 #include <zencore/testing.h>
 #include <zencore/testutils.h>
 #include <zencore/thread.h>
+#include <zencore/trace.h>
 #include <zencore/uid.h>
 #include <zenstore/gc.h>
 
@@ -245,6 +246,8 @@ CasImpl::UpdateManifest()
 CasStore::InsertResult
 CasImpl::InsertChunk(IoBuffer Chunk, const IoHash& ChunkHash)
 {
+	ZEN_TRACE_CPU("CAS::InsertChunk");
+
 	const uint64_t ChunkSize = Chunk.Size();
 
 	if (ChunkSize < m_Config.TinyValueThreshold)
@@ -264,6 +267,8 @@ CasImpl::InsertChunk(IoBuffer Chunk, const IoHash& ChunkHash)
 IoBuffer
 CasImpl::FindChunk(const IoHash& ChunkHash)
 {
+	ZEN_TRACE_CPU("CAS::FindChunk");
+
 	if (IoBuffer Found = m_SmallStrategy.FindChunk(ChunkHash))
 	{
 		return Found;