Additional debugging for protocol stream deadlock reported by

Matt Brown.

2 files changed, 20 insertions, 0 deletions

diff --git a/lib/server/Protocol.cpp b/lib/server/Protocol.cpp
index 4398a58f..77b3269a 100644
--- a/lib/server/Protocol.cpp
+++ b/lib/server/Protocol.cpp
@@ -749,8 +749,10 @@ void Protocol::SendStream(IOStream &rStream)
 			}
 			
 			// Send final byte to finish the stream
+			BOX_TRACE("Sending end of stream byte");
 			uint8_t endOfStream = ProtocolStreamHeader_EndOfStream;
 			mrStream.Write(&endOfStream, 1);
+			BOX_TRACE("Sent end of stream byte");
 		}
 		catch(...)
 		{
@@ -788,6 +790,7 @@ int Protocol::SendStreamSendBlock(uint8_t *Block, int BytesInBlock)
 	// Quick sanity check
 	if(BytesInBlock == 0)
 	{
+		BOX_TRACE("Zero size block, not sending anything");
 		return 0;
 	}
 	
@@ -813,6 +816,8 @@ int Protocol::SendStreamSendBlock(uint8_t *Block, int BytesInBlock)
 		}
 	}
 	ASSERT(header > 0);
+	BOX_TRACE("Sending header byte " << header << " plus " << writeSize <<
+		" bytes to stream");
 	
 	// Store the header
 	Block[-1] = header;
@@ -820,6 +825,7 @@ int Protocol::SendStreamSendBlock(uint8_t *Block, int BytesInBlock)
 	// Write everything out
 	mrStream.Write(Block - 1, writeSize + 1);
 	
+	BOX_TRACE("Sent " << (writeSize+1) << " bytes to stream");
 	// move the remainer to the beginning of the block for the next time round
 	if(writeSize != BytesInBlock)
 	{
diff --git a/lib/server/ProtocolUncertainStream.cpp b/lib/server/ProtocolUncertainStream.cpp
index 9c15455d..b8abbfa1 100644
--- a/lib/server/ProtocolUncertainStream.cpp
+++ b/lib/server/ProtocolUncertainStream.cpp
@@ -77,11 +77,15 @@ int ProtocolUncertainStream::Read(void *pBuffer, int NBytes, int Timeout)
 				toRead = mBytesLeftInCurrentBlock;
 			}
 			
+			BOX_TRACE("Reading " << toRead << " bytes from stream");
+	
 			// Read it
 			int r = mrSource.Read(((uint8_t*)pBuffer) + read, toRead, Timeout);
 			// Give up now if it didn't return anything
 			if(r == 0)
 			{
+				BOX_TRACE("Read " << r << " bytes from "
+					"stream, returning");
 				return read;
 			}
 			
@@ -92,6 +96,8 @@ int ProtocolUncertainStream::Read(void *pBuffer, int NBytes, int Timeout)
 			// stop now if the stream returned less than we asked for -- avoid blocking
 			if(r != toRead)
 			{
+				BOX_TRACE("Read " << r << " bytes from "
+					"stream, returning");
 				return read;
 			}
 		}
@@ -102,6 +108,9 @@ int ProtocolUncertainStream::Read(void *pBuffer, int NBytes, int Timeout)
 			if(mrSource.Read(&header, 1, Timeout) == 0)
 			{
 				// Didn't get the byte, return now
+				BOX_TRACE("Read 0 bytes of block header, "
+					"returning with " << read << " bytes "
+					"read this time");
 				return read;
 			}
 			
@@ -110,6 +119,8 @@ int ProtocolUncertainStream::Read(void *pBuffer, int NBytes, int Timeout)
 			{
 				// All done.
 				mFinished = true;
+				BOX_TRACE("Stream finished, returning with " <<
+					read << " bytes read this time");
 				return read;
 			}
 			else if(header <= Protocol::ProtocolStreamHeader_MaxEncodedSizeValue)
@@ -127,6 +138,9 @@ int ProtocolUncertainStream::Read(void *pBuffer, int NBytes, int Timeout)
 				// Bad. It used the reserved values.
 				THROW_EXCEPTION(ServerException, ProtocolUncertainStreamBadBlockHeader)	
 			}
+
+			BOX_TRACE("Next block has " <<
+				mBytesLeftInCurrentBlock << "bytes");
 		}
 	}