Better error responses/logging in project store request (#217)

* Better error responses/logging in project store request
* changelog

3 files changed, 163 insertions, 110 deletions

diff --git a/CHANGELOG.md b/CHANGELOG.md
index 61265733d..a4b9be7a0 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -1,4 +1,7 @@
 ##
+- Improvement: Clearer error messages and logging when requests to project store fails
+
+## 0.2.2
 - Feature: Added info (GET) endpoints for structured cache
  - `/z$` - get a list of namespaces and global info
  - `/z$/{namespace}` - get list of buckets in a namespace and namespace related info
diff --git a/zenserver/projectstore.cpp b/zenserver/projectstore.cpp
index 1779bfb3c..1885a6b1c 100644
--- a/zenserver/projectstore.cpp
+++ b/zenserver/projectstore.cpp
@@ -1477,7 +1477,7 @@ ProjectStore::GetProjectsList()
 	return Response.Save().AsArray();
 }
 
-HttpResponseCode
+std::pair<HttpResponseCode, std::string>
 ProjectStore::GetProjectFiles(const std::string_view ProjectId, const std::string_view OplogId, bool FilterClient, CbObject& OutPayload)
 {
 	using namespace std::literals;
@@ -1485,16 +1485,14 @@ ProjectStore::GetProjectFiles(const std::string_view ProjectId, const std::strin
 	Ref<ProjectStore::Project> Project = OpenProject(ProjectId);
 	if (!Project)
 	{
-		ZEN_INFO("Project file request for unknown project '{}'", ProjectId);
-		return HttpResponseCode::NotFound;
+		return {HttpResponseCode::NotFound, fmt::format("Project files request for unknown project '{}'", ProjectId)};
 	}
 
 	ProjectStore::Oplog* FoundLog = Project->OpenOplog(OplogId);
 
 	if (!FoundLog)
 	{
-		ZEN_INFO("Project file for unknown oplog '{}/{}'", ProjectId, OplogId);
-		return HttpResponseCode::NotFound;
+		return {HttpResponseCode::NotFound, fmt::format("Project files for unknown oplog '{}/{}'", ProjectId, OplogId)};
 	}
 
 	CbObjectWriter Response;
@@ -1513,10 +1511,10 @@ ProjectStore::GetProjectFiles(const std::string_view ProjectId, const std::strin
 
 	Response.EndArray();
 	OutPayload = Response.Save();
-	return HttpResponseCode::OK;
+	return {HttpResponseCode::OK, {}};
 }
 
-HttpResponseCode
+std::pair<HttpResponseCode, std::string>
 ProjectStore::GetChunkInfo(const std::string_view ProjectId,
 						   const std::string_view OplogId,
 						   const std::string_view ChunkId,
@@ -1527,21 +1525,19 @@ ProjectStore::GetChunkInfo(const std::string_view ProjectId,
 	Ref<ProjectStore::Project> Project = OpenProject(ProjectId);
 	if (!Project)
 	{
-		ZEN_INFO("Chunk info request for unknown project '{}'", ProjectId);
-		return HttpResponseCode::NotFound;
+		return {HttpResponseCode::NotFound, fmt::format("Chunk info request for unknown project '{}'", ProjectId)};
 	}
 
 	ProjectStore::Oplog* FoundLog = Project->OpenOplog(OplogId);
 
 	if (!FoundLog)
 	{
-		ZEN_INFO("Chunk info request for unknown oplog '{}/{}'", ProjectId, OplogId);
-		return HttpResponseCode::NotFound;
+		return {HttpResponseCode::NotFound, fmt::format("Chunk info request for unknown oplog '{}/{}'", ProjectId, OplogId)};
 	}
 	if (ChunkId.size() != 2 * sizeof(Oid::OidBits))
 	{
-		ZEN_INFO("Chunk info request for invalid chunk id '{}/{}'/'{}'", ProjectId, OplogId, ChunkId);
-		return HttpResponseCode::BadRequest;
+		return {HttpResponseCode::BadRequest,
+				fmt::format("Chunk info request for invalid chunk id '{}/{}'/'{}'", ProjectId, OplogId, ChunkId)};
 	}
 
 	const Oid Obj = Oid::FromHexString(ChunkId);
@@ -1549,8 +1545,7 @@ ProjectStore::GetChunkInfo(const std::string_view ProjectId,
 	IoBuffer Chunk = FoundLog->FindChunk(Obj);
 	if (!Chunk)
 	{
-		ZEN_DEBUG("chunk - '{}/{}/{}' MISSING", ProjectId, OplogId, ChunkId);
-		return HttpResponseCode::NotFound;
+		return {HttpResponseCode::NotFound, {}};
 	}
 
 	uint64_t ChunkSize = Chunk.GetSize();
@@ -1566,39 +1561,36 @@ ProjectStore::GetChunkInfo(const std::string_view ProjectId,
 	CbObjectWriter Response;
 	Response << "size"sv << ChunkSize;
 	OutPayload = Response.Save();
-	return HttpResponseCode::OK;
+	return {HttpResponseCode::OK, {}};
 }
 
-HttpResponseCode
-ProjectStore::GetChunk(const std::string_view ProjectId,
-					   const std::string_view OplogId,
-					   const std::string_view ChunkId,
-					   uint64_t				  Offset,
-					   uint64_t				  Size,
-					   ZenContentType		  AcceptType,
-					   IoBuffer&			  OutChunk)
+std::pair<HttpResponseCode, std::string>
+ProjectStore::GetChunkRange(const std::string_view ProjectId,
+							const std::string_view OplogId,
+							const std::string_view ChunkId,
+							uint64_t			   Offset,
+							uint64_t			   Size,
+							ZenContentType		   AcceptType,
+							IoBuffer&			   OutChunk)
 {
 	bool IsOffset = Offset != 0 || Size != ~(0ull);
 
 	Ref<ProjectStore::Project> Project = OpenProject(ProjectId);
 	if (!Project)
 	{
-		ZEN_INFO("Chunk request for unknown project '{}'", ProjectId);
-		return HttpResponseCode::NotFound;
+		return {HttpResponseCode::NotFound, fmt::format("Chunk request for unknown project '{}'", ProjectId)};
 	}
 
 	ProjectStore::Oplog* FoundLog = Project->OpenOplog(OplogId);
 
 	if (!FoundLog)
 	{
-		ZEN_INFO("Chunk request for unknown oplog '{}/{}'", ProjectId, OplogId);
-		return HttpResponseCode::NotFound;
+		return {HttpResponseCode::NotFound, fmt::format("Chunk info request for unknown oplog '{}/{}'", ProjectId, OplogId)};
 	}
 
 	if (ChunkId.size() != 2 * sizeof(Oid::OidBits))
 	{
-		ZEN_INFO("Chunk request for invalid chunk id '{}/{}/{}'", ProjectId, OplogId, ChunkId);
-		return HttpResponseCode::BadRequest;
+		return {HttpResponseCode::BadRequest, fmt::format("Chunk request for invalid chunk id '{}/{}'/'{}'", ProjectId, OplogId, ChunkId)};
 	}
 
 	const Oid Obj = Oid::FromHexString(ChunkId);
@@ -1606,8 +1598,7 @@ ProjectStore::GetChunk(const std::string_view ProjectId,
 	IoBuffer Chunk = FoundLog->FindChunk(Obj);
 	if (!Chunk)
 	{
-		ZEN_DEBUG("chunk - '{}/{}/{}' MISSING", ProjectId, OplogId, ChunkId);
-		return HttpResponseCode::NotFound;
+		return {HttpResponseCode::NotFound, {}};
 	}
 
 	OutChunk					= Chunk;
@@ -1664,20 +1655,34 @@ ProjectStore::GetChunk(const std::string_view ProjectId,
 		OutChunk.SetContentType(ContentType);
 	}
 
-	ZEN_DEBUG("chunk - '{}/{}/{}' '{}'", ProjectId, OplogId, ChunkId, ToString(ContentType));
-
-	return HttpResponseCode::OK;
+	return {HttpResponseCode::OK, {}};
 }
 
-HttpResponseCode
-ProjectStore::GetChunk(const std::string_view Cid, ZenContentType AcceptType, IoBuffer& OutChunk)
+std::pair<HttpResponseCode, std::string>
+ProjectStore::GetChunk(const std::string_view ProjectId,
+					   const std::string_view OplogId,
+					   const std::string_view Cid,
+					   ZenContentType		  AcceptType,
+					   IoBuffer&			  OutChunk)
 {
 	using namespace std::literals;
 
+	Ref<ProjectStore::Project> Project = OpenProject(ProjectId);
+	if (!Project)
+	{
+		return {HttpResponseCode::NotFound, fmt::format("Chunk request for unknown project '{}'", ProjectId)};
+	}
+
+	ProjectStore::Oplog* FoundLog = Project->OpenOplog(OplogId);
+
+	if (!FoundLog)
+	{
+		return {HttpResponseCode::NotFound, fmt::format("Chunk info request for unknown oplog '{}/{}'", ProjectId, OplogId)};
+	}
+
 	if (Cid.length() != IoHash::StringLength)
 	{
-		ZEN_INFO("Chunk request for invalid chunk hash '{}'", Cid);
-		return HttpResponseCode::BadRequest;
+		return {HttpResponseCode::BadRequest, fmt::format("Chunk request for invalid chunk id '{}/{}'/'{}'", ProjectId, OplogId, Cid)};
 	}
 
 	const IoHash Hash = IoHash::FromHexString(Cid);
@@ -1685,8 +1690,7 @@ ProjectStore::GetChunk(const std::string_view Cid, ZenContentType AcceptType, Io
 
 	if (!OutChunk)
 	{
-		ZEN_DEBUG("chunk - '{}' MISSING", Cid);
-		return HttpResponseCode::NotFound;
+		return {HttpResponseCode::NotFound, fmt::format("chunk - '{}' MISSING", Cid)};
 	}
 
 	if (AcceptType == HttpContentType::kBinary)
@@ -1699,7 +1703,7 @@ ProjectStore::GetChunk(const std::string_view Cid, ZenContentType AcceptType, Io
 	{
 		OutChunk.SetContentType(HttpContentType::kCompressedBinary);
 	}
-	return HttpResponseCode::OK;
+	return {HttpResponseCode::OK, {}};
 }
 
 //////////////////////////////////////////////////////////////////////////
@@ -1871,13 +1875,23 @@ HttpProjectService::HttpProjectService(CidStore& Store, ProjectStore* Projects)
 
 			const bool FilterClient = Params.GetValue("filter"sv) == "client"sv;
 
-			CbObject		 ResponsePayload;
-			HttpResponseCode Response = m_ProjectStore->GetProjectFiles(ProjectId, OplogId, FilterClient, ResponsePayload);
-			if (Response != HttpResponseCode::OK)
+			CbObject								 ResponsePayload;
+			std::pair<HttpResponseCode, std::string> Result =
+				m_ProjectStore->GetProjectFiles(ProjectId, OplogId, FilterClient, ResponsePayload);
+			if (Result.first == HttpResponseCode::OK)
 			{
-				return HttpReq.WriteResponse(Response);
+				return HttpReq.WriteResponse(HttpResponseCode::OK, ResponsePayload);
 			}
-			return HttpReq.WriteResponse(Response, ResponsePayload);
+			else
+			{
+				ZEN_DEBUG("Request {}: '{}' failed with {}. Reason: `{}`",
+						  ToString(HttpReq.RequestVerb()),
+						  HttpReq.QueryString(),
+						  static_cast<int>(Result.first),
+						  Result.second);
+			}
+
+			return HttpReq.WriteResponse(Result.first, HttpContentType::kText, Result.second);
 		},
 		HttpVerb::kGet);
 
@@ -1890,13 +1904,25 @@ HttpProjectService::HttpProjectService(CidStore& Store, ProjectStore* Projects)
 			const auto& OplogId	  = Req.GetCapture(2);
 			const auto& ChunkId	  = Req.GetCapture(3);
 
-			CbObject		 ResponsePayload;
-			HttpResponseCode Response = m_ProjectStore->GetChunkInfo(ProjectId, OplogId, ChunkId, ResponsePayload);
-			if (Response != HttpResponseCode::OK)
+			CbObject								 ResponsePayload;
+			std::pair<HttpResponseCode, std::string> Result = m_ProjectStore->GetChunkInfo(ProjectId, OplogId, ChunkId, ResponsePayload);
+			if (Result.first == HttpResponseCode::OK)
+			{
+				return HttpReq.WriteResponse(HttpResponseCode::OK, ResponsePayload);
+			}
+			else if (Result.first == HttpResponseCode::NotFound)
 			{
-				return HttpReq.WriteResponse(Response);
+				ZEN_DEBUG("chunk - '{}/{}/{}' MISSING", ProjectId, OplogId, ChunkId);
 			}
-			HttpReq.WriteResponse(HttpResponseCode::OK, ResponsePayload);
+			else
+			{
+				ZEN_DEBUG("Request {}: '{}' failed with {}. Reason: `{}`",
+						  ToString(HttpReq.RequestVerb()),
+						  HttpReq.QueryString(),
+						  static_cast<int>(Result.first),
+						  Result.second);
+			}
+			return HttpReq.WriteResponse(Result.first, HttpContentType::kText, Result.second);
 		},
 		HttpVerb::kGet);
 
@@ -1940,15 +1966,27 @@ HttpProjectService::HttpProjectService(CidStore& Store, ProjectStore* Projects)
 
 			HttpContentType AcceptType = HttpReq.AcceptContentType();
 
-			IoBuffer		 Chunk;
-			HttpResponseCode Response = m_ProjectStore->GetChunk(ProjectId, OplogId, ChunkId, Offset, Size, AcceptType, Chunk);
-			if (Response != HttpResponseCode::OK)
+			IoBuffer								 Chunk;
+			std::pair<HttpResponseCode, std::string> Result =
+				m_ProjectStore->GetChunkRange(ProjectId, OplogId, ChunkId, Offset, Size, AcceptType, Chunk);
+			if (Result.first == HttpResponseCode::OK)
 			{
-				return HttpReq.WriteResponse(Response);
+				ZEN_DEBUG("chunk - '{}/{}/{}' '{}'", ProjectId, OplogId, ChunkId, ToString(Chunk.GetContentType()));
+				return HttpReq.WriteResponse(HttpResponseCode::OK, Chunk.GetContentType(), Chunk);
 			}
-
-			m_Log.debug("chunk - '{}/{}/{}' '{}'", ProjectId, OplogId, ChunkId, ToString(Chunk.GetContentType()));
-			return HttpReq.WriteResponse(HttpResponseCode::OK, Chunk.GetContentType(), Chunk);
+			else if (Result.first == HttpResponseCode::NotFound)
+			{
+				ZEN_DEBUG("chunk - '{}/{}/{}' MISSING", ProjectId, OplogId, ChunkId);
+			}
+			else
+			{
+				ZEN_DEBUG("Request {}: '{}' failed with {}. Reason: `{}`",
+						  ToString(HttpReq.RequestVerb()),
+						  HttpReq.QueryString(),
+						  static_cast<int>(Result.first),
+						  Result.second);
+			}
+			return HttpReq.WriteResponse(Result.first, HttpContentType::kText, Result.second);
 		},
 		HttpVerb::kGet | HttpVerb::kHead);
 
@@ -1957,31 +1995,31 @@ HttpProjectService::HttpProjectService(CidStore& Store, ProjectStore* Projects)
 		[this](HttpRouterRequest& Req) {
 			HttpServerRequest& HttpReq = Req.ServerRequest();
 
-			const auto&		HashString = Req.GetCapture(3);
-			IoHash			Hash	   = IoHash::FromHexString(HashString);
+			const auto&		ProjectId  = Req.GetCapture(1);
+			const auto&		OplogId	   = Req.GetCapture(2);
+			const auto&		Cid		   = Req.GetCapture(3);
 			HttpContentType AcceptType = HttpReq.AcceptContentType();
 
-			if (AcceptType == HttpContentType::kUnknownContentType)
+			IoBuffer								 Value;
+			std::pair<HttpResponseCode, std::string> Result = m_ProjectStore->GetChunk(ProjectId, OplogId, Cid, AcceptType, Value);
+
+			if (Result.first == HttpResponseCode::OK)
 			{
-				AcceptType = HttpContentType::kBinary;
+				return HttpReq.WriteResponse(HttpResponseCode::OK, Value.GetContentType(), Value);
 			}
-
-			HttpContentType ContentType = HttpContentType::kCompressedBinary;
-			IoBuffer		Value		= m_CidStore.FindChunkByCid(Hash);
-
-			if (!Value)
+			else if (Result.first == HttpResponseCode::NotFound)
 			{
-				return HttpReq.WriteResponse(HttpResponseCode::NotFound);
+				ZEN_DEBUG("chunk - '{}/{}/{}' MISSING", ProjectId, OplogId, Cid);
 			}
-
-			if (AcceptType == HttpContentType::kBinary)
+			else
 			{
-				CompressedBuffer Compressed = CompressedBuffer::FromCompressedNoValidate(std::move(Value));
-				Value						= Compressed.Decompress().AsIoBuffer();
-				ContentType					= HttpContentType::kBinary;
+				ZEN_DEBUG("Request {}: '{}' failed with {}. Reason: `{}`",
+						  ToString(HttpReq.RequestVerb()),
+						  HttpReq.QueryString(),
+						  static_cast<int>(Result.first),
+						  Result.second);
 			}
-
-			return HttpReq.WriteResponse(HttpResponseCode::OK, ContentType, Value);
+			return HttpReq.WriteResponse(Result.first, HttpContentType::kText, Result.second);
 		},
 		HttpVerb::kGet);
 
@@ -2994,9 +3032,13 @@ TEST_CASE("project.store.partial.read")
 	}
 	{
 		IoBuffer Chunk;
-		CHECK(ProjectStore.GetChunk(Attachments[OpIds[1]][0].second.DecodeRawHash().ToHexString(),
-									HttpContentType::kCompressedBinary,
-									Chunk) == HttpResponseCode::OK);
+		CHECK(ProjectStore
+				  .GetChunk("proj1"sv,
+							"oplog1"sv,
+							Attachments[OpIds[1]][0].second.DecodeRawHash().ToHexString(),
+							HttpContentType::kCompressedBinary,
+							Chunk)
+				  .first == HttpResponseCode::OK);
 		IoHash			 RawHash;
 		uint64_t		 RawSize;
 		CompressedBuffer Attachment = CompressedBuffer::FromCompressed(SharedBuffer(Chunk), RawHash, RawSize);
@@ -3004,25 +3046,29 @@ TEST_CASE("project.store.partial.read")
 	}
 
 	IoBuffer ChunkResult;
-	CHECK(ProjectStore.GetChunk("proj1"sv,
-								"oplog1"sv,
-								OidAsString(Attachments[OpIds[2]][1].first),
-								0,
-								~0ull,
-								HttpContentType::kCompressedBinary,
-								ChunkResult) == HttpResponseCode::OK);
+	CHECK(ProjectStore
+			  .GetChunkRange("proj1"sv,
+							 "oplog1"sv,
+							 OidAsString(Attachments[OpIds[2]][1].first),
+							 0,
+							 ~0ull,
+							 HttpContentType::kCompressedBinary,
+							 ChunkResult)
+			  .first == HttpResponseCode::OK);
 	CHECK(ChunkResult);
 	CHECK(CompressedBuffer::FromCompressedNoValidate(std::move(ChunkResult)).DecodeRawSize() ==
 		  Attachments[OpIds[2]][1].second.DecodeRawSize());
 
 	IoBuffer PartialChunkResult;
-	CHECK(ProjectStore.GetChunk("proj1"sv,
-								"oplog1"sv,
-								OidAsString(Attachments[OpIds[2]][1].first),
-								5,
-								1773,
-								HttpContentType::kCompressedBinary,
-								PartialChunkResult) == HttpResponseCode::OK);
+	CHECK(ProjectStore
+			  .GetChunkRange("proj1"sv,
+							 "oplog1"sv,
+							 OidAsString(Attachments[OpIds[2]][1].first),
+							 5,
+							 1773,
+							 HttpContentType::kCompressedBinary,
+							 PartialChunkResult)
+			  .first == HttpResponseCode::OK);
 	CHECK(PartialChunkResult);
 	IoHash			 PartialRawHash;
 	uint64_t		 PartialRawSize;
diff --git a/zenserver/projectstore.h b/zenserver/projectstore.h
index f30845fd1..8267bd9e0 100644
--- a/zenserver/projectstore.h
+++ b/zenserver/projectstore.h
@@ -239,23 +239,27 @@ public:
 	virtual void		  CollectGarbage(GcContext& GcCtx) override;
 	virtual GcStorageSize StorageSize() const override;
 
-	CbArray			 GetProjectsList();
-	HttpResponseCode GetProjectFiles(const std::string_view ProjectId,
-									 const std::string_view OplogId,
-									 bool					FilterClient,
-									 CbObject&				OutPayload);
-	HttpResponseCode GetChunkInfo(const std::string_view ProjectId,
-								  const std::string_view OplogId,
-								  const std::string_view ChunkId,
-								  CbObject&				 OutPayload);
-	HttpResponseCode GetChunk(const std::string_view ProjectId,
-							  const std::string_view OplogId,
-							  const std::string_view ChunkId,
-							  uint64_t				 Offset,
-							  uint64_t				 Size,
-							  ZenContentType		 AcceptType,
-							  IoBuffer&				 OutChunk);
-	HttpResponseCode GetChunk(const std::string_view Cid, ZenContentType AcceptType, IoBuffer& OutChunk);
+	CbArray									 GetProjectsList();
+	std::pair<HttpResponseCode, std::string> GetProjectFiles(const std::string_view ProjectId,
+															 const std::string_view OplogId,
+															 bool					FilterClient,
+															 CbObject&				OutPayload);
+	std::pair<HttpResponseCode, std::string> GetChunkInfo(const std::string_view ProjectId,
+														  const std::string_view OplogId,
+														  const std::string_view ChunkId,
+														  CbObject&				 OutPayload);
+	std::pair<HttpResponseCode, std::string> GetChunkRange(const std::string_view ProjectId,
+														   const std::string_view OplogId,
+														   const std::string_view ChunkId,
+														   uint64_t				  Offset,
+														   uint64_t				  Size,
+														   ZenContentType		  AcceptType,
+														   IoBuffer&			  OutChunk);
+	std::pair<HttpResponseCode, std::string> GetChunk(const std::string_view ProjectId,
+													  const std::string_view OplogId,
+													  const std::string_view Cid,
+													  ZenContentType		 AcceptType,
+													  IoBuffer&				 OutChunk);
 
 private:
 	spdlog::logger&						m_Log;