SPDY - Better SPDY error logging in NetLog.

Moved all logging messages into net_log_.AddEvents.

BUG=112657
R=willchan
TEST=network unit tests.

Review URL: http://codereview.chromium.org/9424041

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@123317 0039d316-1c4b-4281-b951-d872f2087c98

1 files changed, 136 insertions, 0 deletions

diff --git a/net/spdy/spdy_stream_unittest.cc b/net/spdy/spdy_stream_unittest.cc
index b722917..f29b99e 100644
--- a/net/spdy/spdy_stream_unittest.cc
+++ b/net/spdy/spdy_stream_unittest.cc
@@ -4,6 +4,7 @@
 
 #include "base/memory/ref_counted.h"
 #include "net/base/completion_callback.h"
+#include "net/base/net_log_unittest.h"
 #include "net/spdy/spdy_stream.h"
 #include "net/spdy/spdy_http_utils.h"
 #include "net/spdy/spdy_session.h"
@@ -265,5 +266,140 @@ TEST_F(SpdyStreamTest, PushedStream) {
   EXPECT_EQ(kStreamUrl, stream->GetUrl().spec());
 }
 
+TEST_F(SpdyStreamTest, StreamError) {
+  SpdySessionDependencies session_deps;
+
+  session_ = SpdySessionDependencies::SpdyCreateSession(&session_deps);
+  SpdySessionPoolPeer pool_peer_(session_->spdy_session_pool());
+
+  const SpdyHeaderInfo kSynStartHeader = {
+    spdy::SYN_STREAM,
+    1,
+    0,
+    net::ConvertRequestPriorityToSpdyPriority(LOWEST),
+    spdy::CONTROL_FLAG_NONE,
+    false,
+    spdy::INVALID,
+    NULL,
+    0,
+    spdy::DATA_FLAG_NONE
+  };
+  static const char* const kGetHeaders[] = {
+    "method",
+    "GET",
+    "scheme",
+    "http",
+    "host",
+    "www.google.com",
+    "path",
+    "/",
+    "version",
+    "HTTP/1.1",
+  };
+  scoped_ptr<spdy::SpdyFrame> req(
+      ConstructSpdyPacket(
+          kSynStartHeader, NULL, 0, kGetHeaders, arraysize(kGetHeaders) / 2));
+  scoped_ptr<spdy::SpdyFrame> msg(
+      ConstructSpdyBodyFrame("\0hello!\xff", 8));
+  MockWrite writes[] = {
+    CreateMockWrite(*req),
+    CreateMockWrite(*msg),
+  };
+  writes[0].sequence_number = 0;
+  writes[1].sequence_number = 2;
+
+  scoped_ptr<spdy::SpdyFrame> resp(ConstructSpdyGetSynReply(NULL, 0, 1));
+  scoped_ptr<spdy::SpdyFrame> echo(
+      ConstructSpdyBodyFrame("\0hello!\xff", 8));
+  MockRead reads[] = {
+    CreateMockRead(*resp),
+    CreateMockRead(*echo),
+    MockRead(ASYNC, 0, 0),  // EOF
+  };
+  reads[0].sequence_number = 1;
+  reads[1].sequence_number = 3;
+  reads[2].sequence_number = 4;
+
+  net::CapturingBoundNetLog log(net::CapturingNetLog::kUnbounded);
+
+  scoped_ptr<OrderedSocketData> data(
+      new OrderedSocketData(reads, arraysize(reads),
+                            writes, arraysize(writes)));
+  MockConnect connect_data(SYNCHRONOUS, OK);
+  data->set_connect_data(connect_data);
+
+  session_deps.socket_factory->AddSocketDataProvider(data.get());
+  SpdySession::SetSSLMode(false);
+
+  scoped_refptr<SpdySession> session(CreateSpdySession());
+  const char* kStreamUrl = "http://www.google.com/";
+  GURL url(kStreamUrl);
+
+  HostPortPair host_port_pair("www.google.com", 80);
+  scoped_refptr<TransportSocketParams> transport_params(
+      new TransportSocketParams(host_port_pair, LOWEST, false, false));
+
+  scoped_ptr<ClientSocketHandle> connection(new ClientSocketHandle);
+  EXPECT_EQ(OK, connection->Init(host_port_pair.ToString(), transport_params,
+                                 LOWEST, CompletionCallback(),
+                                 session_->GetTransportSocketPool(),
+                                 log.bound()));
+  session->InitializeWithSocket(connection.release(), false, OK);
+
+  scoped_refptr<SpdyStream> stream;
+  ASSERT_EQ(
+      OK,
+      session->CreateStream(url, LOWEST, &stream, log.bound(),
+                            CompletionCallback()));
+  scoped_refptr<IOBufferWithSize> buf(new IOBufferWithSize(8));
+  memcpy(buf->data(), "\0hello!\xff", 8);
+  TestCompletionCallback callback;
+
+  scoped_ptr<TestSpdyStreamDelegate> delegate(
+      new TestSpdyStreamDelegate(stream.get(), buf.get(), callback.callback()));
+  stream->SetDelegate(delegate.get());
+
+  EXPECT_FALSE(stream->HasUrl());
+
+  linked_ptr<spdy::SpdyHeaderBlock> headers(new spdy::SpdyHeaderBlock);
+  (*headers)["method"] = "GET";
+  (*headers)["scheme"] = url.scheme();
+  (*headers)["host"] = url.host();
+  (*headers)["path"] = url.path();
+  (*headers)["version"] = "HTTP/1.1";
+  stream->set_spdy_headers(headers);
+  EXPECT_TRUE(stream->HasUrl());
+  EXPECT_EQ(kStreamUrl, stream->GetUrl().spec());
+
+  EXPECT_EQ(ERR_IO_PENDING, stream->SendRequest(true));
+
+  const spdy::SpdyStreamId stream_id = stream->stream_id();
+
+  EXPECT_EQ(OK, callback.WaitForResult());
+
+  EXPECT_TRUE(delegate->send_headers_completed());
+  EXPECT_EQ("200", (*delegate->response())["status"]);
+  EXPECT_EQ("HTTP/1.1", (*delegate->response())["version"]);
+  EXPECT_EQ(std::string("\0hello!\xff", 8), delegate->received_data());
+  EXPECT_EQ(8, delegate->data_sent());
+  EXPECT_TRUE(delegate->closed());
+
+  // Check that the NetLog was filled reasonably.
+  net::CapturingNetLog::EntryList entries;
+  log.GetEntries(&entries);
+  EXPECT_LT(0u, entries.size());
+
+  // Check that we logged SPDY_STREAM_ERROR correctly.
+  int pos = net::ExpectLogContainsSomewhere(
+      entries, 0,
+      net::NetLog::TYPE_SPDY_STREAM_ERROR,
+      net::NetLog::PHASE_NONE);
+
+  CapturingNetLog::Entry entry = entries[pos];
+  NetLogSpdyStreamErrorParameter* request_params =
+      static_cast<NetLogSpdyStreamErrorParameter*>(
+          entry.extra_parameters.get());
+  EXPECT_EQ(stream_id, request_params->stream_id());
+}
 
 }  // namespace net