Add trace support for zen CLI command (#296)

- This change adds support for `--trace`, `--tracehost` and `--tracefile` command arguments to enable and control tracing to Insights
- It also adds profiling scopes primarily to build download command related code

1 files changed, 80 insertions, 3 deletions

diff --git a/src/zen/cmds/builds_cmd.cpp b/src/zen/cmds/builds_cmd.cpp
index fb9da021d..eb0650c4d 100644
--- a/src/zen/cmds/builds_cmd.cpp
+++ b/src/zen/cmds/builds_cmd.cpp
@@ -12,6 +12,7 @@
 #include <zencore/logging.h>
 #include <zencore/scopeguard.h>
 #include <zencore/string.h>
+#include <zencore/trace.h>
 #include <zencore/uid.h>
 #include <zenhttp/formatters.h>
 #include <zenhttp/httpclient.h>
@@ -180,6 +181,8 @@ namespace {
 
 	void CleanDirectory(const std::filesystem::path& Path, std::span<const std::string_view> ExcludeDirectories)
 	{
+		ZEN_TRACE_CPU("CleanDirectory");
+
 		DirectoryContent LocalDirectoryContent;
 		GetDirectoryContent(Path, DirectoryContentFlags::IncludeDirs | DirectoryContentFlags::IncludeFiles, LocalDirectoryContent);
 		for (const std::filesystem::path& LocalFilePath : LocalDirectoryContent.Files)
@@ -352,6 +355,8 @@ namespace {
 		std::function<bool(std::string_view RelativePath, uint64_t Size, uint32_t Attributes)>&& IsAcceptedFile,
 		ChunkingController&																		 ChunkController)
 	{
+		ZEN_TRACE_CPU("ScanAndChunkFolder");
+
 		FolderContent Content = GetFolderContent(
 			GetFolderContentStats,
 			Path,
@@ -506,6 +511,8 @@ namespace {
 													   const std::span<const uint32_t>&						   LooseChunkIndexes,
 													   const std::span<const ChunkBlockDescription>&		   BlockDescriptions)
 	{
+		ZEN_TRACE_CPU("CalculateAbsoluteChunkOrders");
+
 #if EXTRA_VERIFY
 		std::vector<IoHash> TmpAbsoluteChunkHashes;
 		TmpAbsoluteChunkHashes.reserve(LocalChunkHashes.size());
@@ -572,6 +579,8 @@ namespace {
 								   std::vector<uint64_t>&						 OutLocalChunkRawSizes,
 								   std::vector<uint32_t>&						 OutLocalChunkOrders)
 	{
+		ZEN_TRACE_CPU("CalculateLocalChunkOrders");
+
 		std::vector<IoHash>	  AbsoluteChunkHashes;
 		std::vector<uint64_t> AbsoluteChunkRawSizes;
 		AbsoluteChunkHashes.insert(AbsoluteChunkHashes.end(), LooseChunkHashes.begin(), LooseChunkHashes.end());
@@ -955,6 +964,8 @@ namespace {
 		const uint64_t	BlockSize = 256u * 1024u;
 		CompositeBuffer GetRange(uint64_t Offset, uint64_t Size)
 		{
+			ZEN_TRACE_CPU("BufferedOpenFile::GetRange");
+
 			ZEN_ASSERT((CacheBlockIndex == (uint64_t)-1) || Cache);
 			auto _ = MakeGuard([&]() { ZEN_ASSERT((CacheBlockIndex == (uint64_t)-1) || Cache); });
 
@@ -1022,6 +1033,8 @@ namespace {
 
 		CompositeBuffer GetRange(uint32_t SequenceIndex, uint64_t Offset, uint64_t Size)
 		{
+			ZEN_TRACE_CPU("ReadFileCache::GetRange");
+
 			auto CacheIt = std::find_if(m_OpenFiles.begin(), m_OpenFiles.end(), [SequenceIndex](const auto& Lhs) {
 				return Lhs.first == SequenceIndex;
 			});
@@ -1069,6 +1082,8 @@ namespace {
 
 	CompositeBuffer ValidateBlob(IoBuffer&& Payload, const IoHash& BlobHash, uint64_t& OutCompressedSize, uint64_t& OutDecompressedSize)
 	{
+		ZEN_TRACE_CPU("ValidateBlob");
+
 		if (Payload.GetContentType() != ZenContentType::kCompressedBinary)
 		{
 			throw std::runtime_error(fmt::format("Blob {} ({} bytes) has unexpected content type '{}'",
@@ -3087,6 +3102,8 @@ namespace {
 
 	void VerifyFolder(const ChunkedFolderContent& Content, const std::filesystem::path& Path, bool VerifyFileHash)
 	{
+		ZEN_TRACE_CPU("VerifyFolder");
+
 		ProgressBar			  ProgressBar(UsePlainProgress);
 		std::atomic<uint64_t> FilesVerified(0);
 		std::atomic<uint64_t> FilesFailed(0);
@@ -3133,6 +3150,8 @@ namespace {
 				[&, PathIndex](std::atomic<bool>&) {
 					if (!AbortFlag)
 					{
+						ZEN_TRACE_CPU("VerifyFile_work");
+
 						// TODO: Convert ScheduleWork body to function
 
 						const std::filesystem::path TargetPath = (Path / Content.Paths[PathIndex]).make_preferred();
@@ -3348,6 +3367,8 @@ namespace {
 						  std::atomic<uint32_t>&		   OutChunksComplete,
 						  std::atomic<uint64_t>&		   OutBytesWritten)
 	{
+		ZEN_TRACE_CPU("WriteBlockToDisk");
+
 		std::vector<CompositeBuffer> ChunkBuffers;
 		struct WriteOpData
 		{
@@ -3438,6 +3459,8 @@ namespace {
 					}
 					if (!AbortFlag)
 					{
+						ZEN_TRACE_CPU("WriteBlockToDisk_VerifyHash");
+
 						// Write tracking, updating this must be done without any files open (WriteFileCache)
 						for (const WriteOpData& WriteOp : WriteOps)
 						{
@@ -3449,7 +3472,7 @@ namespace {
 									 IoBufferBuilder::MakeFromFile(GetTempChunkedSequenceFileName(CacheFolderPath, SequenceRawHash)));
 								if (VerifyChunkHash != SequenceRawHash)
 								{
-									throw std::runtime_error(fmt::format("Written hunk sequence {} hash does not match expected hash {}",
+									throw std::runtime_error(fmt::format("Written chunk sequence {} hash does not match expected hash {}",
 																		 VerifyChunkHash,
 																		 SequenceRawHash));
 								}
@@ -3468,6 +3491,8 @@ namespace {
 
 	SharedBuffer Decompress(const CompositeBuffer& CompressedChunk, const IoHash& ChunkHash, const uint64_t ChunkRawSize)
 	{
+		ZEN_TRACE_CPU("Decompress");
+
 		IoHash			 RawHash;
 		uint64_t		 RawSize;
 		CompressedBuffer Compressed = CompressedBuffer::FromCompressed(CompressedChunk, RawHash, RawSize);
@@ -3506,6 +3531,8 @@ namespace {
 						  WriteFileCache&													  OpenFileCache,
 						  std::atomic<uint64_t>&											  OutBytesWritten)
 	{
+		ZEN_TRACE_CPU("WriteChunkToDisk");
+
 		for (const ChunkedContentLookup::ChunkSequenceLocation* TargetPtr : ChunkTargets)
 		{
 			const auto&	   Target		 = *TargetPtr;
@@ -3611,6 +3638,8 @@ namespace {
 						   std::atomic<uint32_t>&												  ChunksComplete,
 						   std::atomic<uint64_t>&												  MultipartAttachmentCount)
 	{
+		ZEN_TRACE_CPU("DownloadLargeBlob");
+
 		struct WorkloadData
 		{
 			TemporaryFile TempFile;
@@ -3666,6 +3695,8 @@ namespace {
 							 &WriteToDiskBytes,
 							 SequenceIndexChunksLeftToWriteCounters,
 							 ChunkTargetPtrs](std::atomic<bool>&) {
+								ZEN_TRACE_CPU("DownloadLargeBlob_Work");
+
 								if (!AbortFlag)
 								{
 									uint64_t CompressedSize = Workload->TempFile.FileSize();
@@ -3729,6 +3760,8 @@ namespace {
 											const uint32_t RemoteSequenceIndex = Location->SequenceIndex;
 											if (SequenceIndexChunksLeftToWriteCounters[RemoteSequenceIndex].fetch_sub(1) == 1)
 											{
+												ZEN_TRACE_CPU("VerifyChunkHash");
+
 												const IoHash& SequenceRawHash =
 													RemoteContent.ChunkedContent.SequenceRawHashes[RemoteSequenceIndex];
 												if (NeedHashVerify)
@@ -3743,6 +3776,8 @@ namespace {
 																		ChunkHash));
 													}
 												}
+
+												ZEN_TRACE_CPU("VerifyChunkHashes_rename");
 												std::filesystem::rename(GetTempChunkedSequenceFileName(CacheFolderPath, SequenceRawHash),
 																		GetFinalChunkedSequenceFileName(CacheFolderPath, SequenceRawHash));
 											}
@@ -3784,6 +3819,8 @@ namespace {
 					  bool										WipeTargetFolder,
 					  FolderContent&							OutLocalFolderState)
 	{
+		ZEN_TRACE_CPU("UpdateFolder");
+
 		ZEN_UNUSED(WipeTargetFolder);
 		std::atomic<uint64_t> DownloadedBlocks		   = 0;
 		std::atomic<uint64_t> BlockBytes			   = 0;
@@ -3933,6 +3970,8 @@ namespace {
 		std::atomic<uint32_t> ChunkCountWritten = 0;
 
 		{
+			ZEN_TRACE_CPU("HandleChunks");
+
 			FilteredRate FilteredDownloadedBytesPerSecond;
 			FilteredRate FilteredWrittenBytesPerSecond;
 
@@ -3974,6 +4013,8 @@ namespace {
 						Work.ScheduleWork(
 							NetworkPool,  // GetSyncWorkerPool(),//
 							[&, ChunkHash, RemoteChunkIndex, ChunkTargetPtrs](std::atomic<bool>&) {
+								ZEN_TRACE_CPU("UpdateFolder_LooseChunk");
+
 								if (!AbortFlag)
 								{
 									FilteredDownloadedBytesPerSecond.Start();
@@ -4019,6 +4060,8 @@ namespace {
 												WritePool,
 												[&, ChunkHash, RemoteChunkIndex, ChunkTargetPtrs, CompressedPart = std::move(Payload)](
 													std::atomic<bool>&) {
+													ZEN_TRACE_CPU("UpdateFolder_WriteBlob");
+
 													if (!AbortFlag)
 													{
 														FilteredWrittenBytesPerSecond.Start();
@@ -4066,6 +4109,8 @@ namespace {
 																if (SequenceIndexChunksLeftToWriteCounters[RemoteSequenceIndex].fetch_sub(
 																		1) == 1)
 																{
+																	ZEN_TRACE_CPU("UpdateFolder_VerifyHash");
+
 																	const IoHash& SequenceRawHash =
 																		RemoteContent.ChunkedContent.SequenceRawHashes[RemoteSequenceIndex];
 																	if (NeedHashVerify)
@@ -4077,12 +4122,14 @@ namespace {
 																		if (VerifyChunkHash != SequenceRawHash)
 																		{
 																			throw std::runtime_error(
-																				fmt::format("Written hunk sequence {} hash does not match "
+																				fmt::format("Written chunk sequence {} hash does not match "
 																							"expected hash {}",
 																							VerifyChunkHash,
 																							SequenceRawHash));
 																		}
 																	}
+
+																	ZEN_TRACE_CPU("UpdateFolder_rename");
 																	std::filesystem::rename(
 																		GetTempChunkedSequenceFileName(CacheFolderPath, SequenceRawHash),
 																		GetFinalChunkedSequenceFileName(CacheFolderPath, SequenceRawHash));
@@ -4113,6 +4160,8 @@ namespace {
 					[&, CopyDataIndex](std::atomic<bool>&) {
 						if (!AbortFlag)
 						{
+							ZEN_TRACE_CPU("UpdateFolder_Copy");
+
 							FilteredWrittenBytesPerSecond.Start();
 							const CacheCopyData& CopyData		= CacheCopyDatas[CopyDataIndex];
 							const uint32_t		 LocalPathIndex = LocalLookup.SequenceIndexFirstPathIndex[CopyData.LocalSequenceIndex];
@@ -4205,6 +4254,8 @@ namespace {
 										// Write tracking, updating this must be done without any files open (WriteFileCache)
 										for (const WriteOp& Op : WriteOps)
 										{
+											ZEN_TRACE_CPU("UpdateFolder_Copy_VerifyHash");
+
 											const uint32_t RemoteSequenceIndex = Op.Target->SequenceIndex;
 											if (SequenceIndexChunksLeftToWriteCounters[RemoteSequenceIndex].fetch_sub(1) == 1)
 											{
@@ -4215,10 +4266,12 @@ namespace {
 												if (VerifyChunkHash != SequenceRawHash)
 												{
 													throw std::runtime_error(
-														fmt::format("Written hunk sequence {} hash does not match expected hash {}",
+														fmt::format("Written chunk sequence {} hash does not match expected hash {}",
 																	VerifyChunkHash,
 																	SequenceRawHash));
 												}
+
+												ZEN_TRACE_CPU("UpdateFolder_Copy_rename");
 												std::filesystem::rename(GetTempChunkedSequenceFileName(CacheFolderPath, SequenceRawHash),
 																		GetFinalChunkedSequenceFileName(CacheFolderPath, SequenceRawHash));
 											}
@@ -4268,6 +4321,8 @@ namespace {
 						[&, BlockIndex](std::atomic<bool>&) {
 							if (!AbortFlag)
 							{
+								ZEN_TRACE_CPU("UpdateFolder_HandleBlocks_Read");
+
 								FilteredDownloadedBytesPerSecond.Start();
 								IoBuffer BlockBuffer = Storage.GetBuildBlob(BuildId, BlockDescriptions[BlockIndex].BlockHash);
 								if (!BlockBuffer)
@@ -4288,6 +4343,8 @@ namespace {
 										[&, BlockIndex, BlockBuffer = std::move(Payload)](std::atomic<bool>&) {
 											if (!AbortFlag)
 											{
+												ZEN_TRACE_CPU("UpdateFolder_HandleBlocks_Write");
+
 												FilteredWrittenBytesPerSecond.Start();
 												IoHash			 BlockRawHash;
 												uint64_t		 BlockRawSize;
@@ -4348,6 +4405,8 @@ namespace {
 				}
 			}
 
+			ZEN_TRACE_CPU("HandleChunks_Wait");
+
 			Work.Wait(UsePlainProgress ? 5000 : 200, [&](bool IsAborted, std::ptrdiff_t PendingWork) {
 				ZEN_UNUSED(IsAborted, PendingWork);
 				ZEN_ASSERT(ChunkCountToWrite >= ChunkCountWritten.load());
@@ -4411,12 +4470,16 @@ namespace {
 
 		if (WipeTargetFolder)
 		{
+			ZEN_TRACE_CPU("UpdateFolder_WipeTarget");
+
 			// Clean target folder
 			ZEN_CONSOLE("Wiping {}", Path);
 			CleanDirectory(Path, DefaultExcludeFolders);
 		}
 		else
 		{
+			ZEN_TRACE_CPU("UpdateFolder_RemoveUnused");
+
 			// Remove unused tracked files
 			tsl::robin_map<std::string, uint32_t> RemotePathToRemoteIndex;
 			RemotePathToRemoteIndex.reserve(RemoteContent.Paths.size());
@@ -4468,6 +4531,8 @@ namespace {
 					break;
 				}
 
+				ZEN_TRACE_CPU("UpdateFolder_FinalizeTree");
+
 				size_t		  TargetCount = 1;
 				const IoHash& RawHash	  = Targets[TargetOffset].first;
 				while (Targets[TargetOffset + TargetCount].first == RawHash)
@@ -4480,6 +4545,8 @@ namespace {
 					[&, BaseTargetOffset = TargetOffset, TargetCount](std::atomic<bool>&) {
 						if (!AbortFlag)
 						{
+							ZEN_TRACE_CPU("FinalizeTree_Work");
+
 							size_t						 TargetOffset		   = BaseTargetOffset;
 							const IoHash&				 RawHash			   = Targets[TargetOffset].first;
 							const uint32_t				 FirstTargetPathIndex  = Targets[TargetOffset].second;
@@ -4501,6 +4568,8 @@ namespace {
 							}
 							else
 							{
+								ZEN_TRACE_CPU("FinalizeTree_MoveIntoPlace");
+
 								const std::filesystem::path CacheFilePath = GetFinalChunkedSequenceFileName(CacheFolderPath, RawHash);
 								ZEN_ASSERT_SLOW(std::filesystem::exists(CacheFilePath));
 								CreateDirectories(FirstTargetFilePath.parent_path());
@@ -4522,6 +4591,8 @@ namespace {
 							TargetsComplete++;
 							while (TargetOffset < (BaseTargetOffset + TargetCount))
 							{
+								ZEN_TRACE_CPU("FinalizeTree_Copy");
+
 								ZEN_ASSERT(Targets[TargetOffset].first == RawHash);
 								ZEN_ASSERT_SLOW(std::filesystem::exists(FirstTargetFilePath));
 								const uint32_t				 ExtraTargetPathIndex  = Targets[TargetOffset].second;
@@ -4555,6 +4626,8 @@ namespace {
 				TargetOffset += TargetCount;
 			}
 
+			ZEN_TRACE_CPU("FinalizeTree_Wait");
+
 			Work.Wait(UsePlainProgress ? 5000 : 200, [&](bool IsAborted, std::ptrdiff_t PendingWork) {
 				ZEN_UNUSED(IsAborted, PendingWork);
 				std::string Details = fmt::format("{}/{} files", TargetsComplete.load(), Targets.size());
@@ -4668,6 +4741,8 @@ namespace {
 										  std::vector<ChunkBlockDescription>&			  OutBlockDescriptions,
 										  std::vector<IoHash>&							  OutLooseChunkHashes)
 	{
+		ZEN_TRACE_CPU("GetRemoteContent");
+
 		Stopwatch GetBuildPartTimer;
 		CbObject  BuildPartManifest = Storage.GetBuildPart(BuildId, BuildParts[0].first);
 		ZEN_CONSOLE("GetBuildPart {} ('{}') took {}. Payload size: {}",
@@ -5114,6 +5189,8 @@ namespace {
 						bool						 WipeTargetFolder,
 						bool						 PostDownloadVerify)
 	{
+		ZEN_TRACE_CPU("DownloadFolder");
+
 		Stopwatch DownloadTimer;
 
 		const std::filesystem::path ZenTempFolder = Path / ZenTempFolderName;