Bug 1133873 - some spdy logs r=hurley

netwerk/protocol/http/SpdySession31.cpp

@@ -2057,7 +2057,7 @@ SpdySession31::WriteSegments(nsAHttpSegmentWriter *writer,
         mInputFrameDataStream->SetRecvdData(true);
         rv = ResponseHeadersComplete();
         if (rv == NS_ERROR_ILLEGAL_VALUE) {
-          LOG3(("SpdySession31 %p PROTOCOL_ERROR detected 0x%X\n",
+          LOG3(("SpdySession31 %p ResponseHeadersComplete PROTOCOL_ERROR detected 0x%X\n",
                 this, streamID));
           CleanupStream(mInputFrameDataStream, rv, RST_PROTOCOL_ERROR);
           ChangeDownstreamState(DISCARDING_DATA_FRAME);

netwerk/protocol/http/SpdyStream31.cpp

@@ -1179,17 +1179,26 @@ SpdyStream31::FindHeader(nsCString name,
 nsresult
 SpdyStream31::ConvertHeaders(nsACString &aHeadersOut)
 {
+  LOG3(("SpdyStream31::ConvertHeaders session=%p stream=%p id=0x%x\n",
+        mSession, this, mStreamID));
+
   // :status and :version are required.
   nsDependentCSubstring status, version;
   nsresult rv = FindHeader(NS_LITERAL_CSTRING(":status"),
                            status);
-  if (NS_FAILED(rv))
+  if (NS_FAILED(rv)) {
+    LOG3(("SpdyStream31::ConvertHeaders session=%p stream=%p id=0x%x missing :status\n",
+          mSession, this, mStreamID));
     return (rv == NS_ERROR_NOT_AVAILABLE) ? NS_ERROR_ILLEGAL_VALUE : rv;
+  }
 
   rv = FindHeader(NS_LITERAL_CSTRING(":version"),
                   version);
-  if (NS_FAILED(rv))
+  if (NS_FAILED(rv)) {
+    LOG3(("SpdyStream31::ConvertHeaders session=%p stream=%p id=0x%x missing :version\n",
+          mSession, this, mStreamID));
     return (rv == NS_ERROR_NOT_AVAILABLE) ? NS_ERROR_ILLEGAL_VALUE : rv;
+  }
 
   if (mDecompressedBytes && mDecompressBufferUsed) {
     Telemetry::Accumulate(Telemetry::SPDY_SYN_REPLY_SIZE, mDecompressedBytes);
@@ -1212,31 +1221,51 @@ SpdyStream31::ConvertHeaders(nsACString &aHeadersOut)
   aHeadersOut.Append(status);
   aHeadersOut.AppendLiteral("\r\n");
 
+  LOG3(("SpdyStream31::ConvertHeaders session=%p stream=%p id=0x%x decompressed size %d\n",
+        mSession, this, mStreamID, mDecompressBufferUsed));
+
   const unsigned char *nvpair = reinterpret_cast<unsigned char *>
     (mDecompressBuffer.get()) + 4;
   const unsigned char *lastHeaderByte = reinterpret_cast<unsigned char *>
     (mDecompressBuffer.get()) + mDecompressBufferUsed;
-  if (lastHeaderByte < nvpair)
+  if (lastHeaderByte < nvpair) {
+    LOG3(("SpdyStream31::ConvertHeaders session=%p stream=%p id=0x%x format err 1\n",
+          mSession, this, mStreamID));
     return NS_ERROR_ILLEGAL_VALUE;
+  }
 
   do {
     uint32_t numPairs = PR_ntohl(reinterpret_cast<const uint32_t *>(nvpair)[-1]);
+    LOG3(("SpdyStream31::ConvertHeaders session=%p stream=%p id=0x%x numPairs %d\n",
+          mSession, this, mStreamID, numPairs));
 
     for (uint32_t index = 0; index < numPairs; ++index) {
-      if (lastHeaderByte < nvpair + 4)
+      LOG5(("SpdyStream31::ConvertHeaders session=%p stream=%p id=0x%x index=%u remaining=%u\n",
+            mSession, this, mStreamID, index, lastHeaderByte - nvpair));
+      if (lastHeaderByte < nvpair + 4) {
+        LOG3(("SpdyStream31::ConvertHeaders session=%p stream=%p id=0x%x format err 2\n",
+              mSession, this, mStreamID));
         return NS_ERROR_ILLEGAL_VALUE;
-
+      }
       uint32_t nameLen = (nvpair[0] << 24) + (nvpair[1] << 16) +
         (nvpair[2] << 8) + nvpair[3];
-      if (lastHeaderByte < nvpair + 4 + nameLen)
+      LOG5(("SpdyStream31::ConvertHeaders session=%p stream=%p id=0x%x namelen=%u\n",
+            mSession, this, mStreamID, nameLen));
+      if (lastHeaderByte < nvpair + 4 + nameLen) {
+        LOG3(("SpdyStream31::ConvertHeaders session=%p stream=%p id=0x%x format err 3\n",
+              mSession, this, mStreamID));
         return NS_ERROR_ILLEGAL_VALUE;
+      }
 
       nsDependentCSubstring nameString =
         Substring(reinterpret_cast<const char *>(nvpair) + 4,
                   reinterpret_cast<const char *>(nvpair) + 4 + nameLen);
 
-      if (lastHeaderByte < nvpair + 8 + nameLen)
+      if (lastHeaderByte < nvpair + 8 + nameLen) {
+        LOG3(("SpdyStream31::ConvertHeaders session=%p stream=%p id=0x%x format err 4\n",
+              mSession, this, mStreamID));
         return NS_ERROR_ILLEGAL_VALUE;
+      }
 
       // Look for illegal characters in the nameString.
       // This includes upper case characters and nulls (as they will
@@ -1256,8 +1285,11 @@ SpdyStream31::ConvertHeaders(nsACString &aHeadersOut)
         }
 
         // check for null characters
-        if (*cPtr == '\0')
+        if (*cPtr == '\0') {
+          LOG3(("SpdyStream31::ConvertHeaders session=%p stream=%p id=0x%x unexpected null\n",
+                mSession, this, mStreamID));
           return NS_ERROR_ILLEGAL_VALUE;
+        }
       }
 
       // HTTP Chunked responses are not legal over spdy. We do not need
@@ -1275,9 +1307,13 @@ SpdyStream31::ConvertHeaders(nsACString &aHeadersOut)
       uint32_t valueLen =
         (nvpair[4 + nameLen] << 24) + (nvpair[5 + nameLen] << 16) +
         (nvpair[6 + nameLen] << 8)  +   nvpair[7 + nameLen];
-
-      if (lastHeaderByte < nvpair + 8 + nameLen + valueLen)
+      LOG5(("SpdyStream31::ConvertHeaders session=%p stream=%p id=0x%x valueLen=%u\n",
+            mSession, this, mStreamID, valueLen));
+      if (lastHeaderByte < nvpair + 8 + nameLen + valueLen) {
+        LOG3(("SpdyStream31::ConvertHeaders session=%p stream=%p id=0x%x format err 5\n",
+              mSession, this, mStreamID));
         return NS_ERROR_ILLEGAL_VALUE;
+      }
 
       // spdy transport level headers shouldn't be gatewayed into http/1
       if (!nameString.IsEmpty() && nameString[0] != ':' &&