From 6bedc99f75d00ccf2cabaf10c95e7588e01c509f Mon Sep 17 00:00:00 2001
From: Stefan Boberg <stefan@boberg.org>
Date: Thu, 28 Sep 2023 15:48:00 +0200
Subject: added more context to http response error message (#430)

when a http.sys request response API call fails, we now include more information including metadata about the contents of the reponse (i.e memory/file references including file names/size and chunk offsets/size) to help track down some odd error conditions seen in production
---
 src/zenhttp/httpsys.cpp | 87 +++++++++++++++++++++++++++++++++++++++++++------
 1 file changed, 77 insertions(+), 10 deletions(-)

(limited to 'src/zenhttp/httpsys.cpp')

diff --git a/src/zenhttp/httpsys.cpp b/src/zenhttp/httpsys.cpp
index 886d53143..4d9a3e5b8 100644
--- a/src/zenhttp/httpsys.cpp
+++ b/src/zenhttp/httpsys.cpp
@@ -6,6 +6,8 @@
 #include <zencore/compactbinarybuilder.h>
 #include <zencore/compactbinarypackage.h>
 #include <zencore/except.h>
+#include <zencore/filesystem.h>
+#include <zencore/fmtutils.h>
 #include <zencore/logging.h>
 #include <zencore/scopeguard.h>
 #include <zencore/string.h>
@@ -220,7 +222,7 @@ public:
 		kRequestPending
 	};
 
-	Status HandleCompletion(ULONG IoResult, ULONG_PTR NumberOfBytesTransferred);
+	[[nodiscard]] Status HandleCompletion(ULONG IoResult, ULONG_PTR NumberOfBytesTransferred);
 
 	static void __stdcall IoCompletionCallback(PTP_CALLBACK_INSTANCE Instance,
 											   PVOID				 pContext /* HttpSysServer */,
@@ -380,8 +382,7 @@ HttpMessageResponseRequest::InitializeForPayload(uint16_t ResponseCode, std::spa
 		{
 			// Use direct file transfer
 
-			m_HttpDataChunks.push_back({});
-			auto& Chunk = m_HttpDataChunks.back();
+			auto& Chunk = m_HttpDataChunks.emplace_back();
 
 			Chunk.DataChunkType									   = HttpDataChunkFromFileHandle;
 			Chunk.FromFileHandle.FileHandle						   = FileRef.FileHandle;
@@ -402,8 +403,7 @@ HttpMessageResponseRequest::InitializeForPayload(uint16_t ResponseCode, std::spa
 			{
 				const ULONG ThisChunkSize = gsl::narrow<ULONG>(zen::Min(1 * 1024 * 1024 * 1024, BufferDataSize));
 
-				m_HttpDataChunks.push_back({});
-				auto& Chunk = m_HttpDataChunks.back();
+				auto& Chunk = m_HttpDataChunks.emplace_back();
 
 				Chunk.DataChunkType			  = HttpDataChunkFromMemory;
 				Chunk.FromMemory.pBuffer	  = (void*)WriteCursor;
@@ -593,6 +593,65 @@ HttpMessageResponseRequest::IssueRequest(std::error_code& ErrorCode)
 		);
 	}
 
+	auto EmitReponseDetails = [&](StringBuilderBase& ResponseDetails) -> void {
+		for (int i = 0; i < ThisRequestChunkCount; ++i)
+		{
+			const HTTP_DATA_CHUNK Chunk = m_HttpDataChunks[ThisRequestChunkOffset + i];
+
+			if (i > 0)
+			{
+				ResponseDetails << " + ";
+			}
+
+			switch (Chunk.DataChunkType)
+			{
+				case HttpDataChunkFromMemory:
+					ResponseDetails << "mem:" << uint64_t(Chunk.FromMemory.BufferLength);
+					break;
+
+				case HttpDataChunkFromFileHandle:
+					ResponseDetails << "file:";
+					{
+						ResponseDetails << uint64_t(Chunk.FromFileHandle.ByteRange.StartingOffset.QuadPart) << ","
+										<< uint64_t(Chunk.FromFileHandle.ByteRange.Length.QuadPart) << ",";
+
+						std::error_code		  PathEc;
+						HANDLE				  FileHandle = Chunk.FromFileHandle.FileHandle;
+						std::filesystem::path Path		 = PathFromHandle(FileHandle, PathEc);
+
+						if (PathEc)
+						{
+							ResponseDetails << "bad_file(" << PathEc.message() << ")";
+						}
+						else
+						{
+							const uint64_t FileSize = FileSizeFromHandle(FileHandle);
+							ResponseDetails << Path.u8string() << "(" << FileSize << ")";
+						}
+					}
+					break;
+
+				case HttpDataChunkFromFragmentCache:
+					ResponseDetails << "frag:???";	// We do not use these
+					break;
+
+				case HttpDataChunkFromFragmentCacheEx:
+					ResponseDetails << "frax:???";	// We do not use these
+					break;
+
+#	if 0  // Not available in older Windows SDKs
+				case HttpDataChunkTrailers:
+					ResponseDetails << "trls:???";	// We do not use these
+					break;
+#	endif
+
+				default:
+					ResponseDetails << "???: " << Chunk.DataChunkType;
+					break;
+			}
+		}
+	};
+
 	if (SendResult == NO_ERROR)
 	{
 		// Synchronous completion, but the completion event will still be posted to IOCP
@@ -607,16 +666,24 @@ HttpMessageResponseRequest::IssueRequest(std::error_code& ErrorCode)
 	}
 	else
 	{
+		ErrorCode = MakeErrorCode(SendResult);
+
 		// An error occurred, no completion will be posted to IOCP
 
 		CancelThreadpoolIo(Iocp);
 
-		ZEN_WARN("failed to send HTTP response (error: '{}'), request URL: '{}', request id: {}",
-				 GetSystemErrorAsString(SendResult),
-				 HttpReq->pRawUrl,
-				 HttpReq->RequestId);
+		// Emit diagnostics
 
-		ErrorCode = MakeErrorCode(SendResult);
+		ExtendableStringBuilder<256> ResponseDetails;
+		EmitReponseDetails(ResponseDetails);
+
+		ZEN_WARN("failed to send HTTP response (error {}: '{}'), request URL: '{}', ({}.{}) response: {}",
+				 SendResult,
+				 ErrorCode.message(),
+				 HttpReq->pRawUrl,
+				 Tx.ServerRequest().SessionId(),
+				 HttpReq->RequestId,
+				 ResponseDetails);
 	}
 }
 
-- 
cgit v1.2.3