Log urls and headers in BIDIRECTIONAL_STREAM events

net/http/bidirectional_stream_unittest.cc

 // Copyright 2015 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "net/http/bidirectional_stream.h"
 
 #include <memory>
 
 #include "base/macros.h"
 #include "base/memory/ptr_util.h"
@@ skipping 462 matching lines @@
   EXPECT_EQ("header-value", response_headers.find("header-name")->second);
   EXPECT_EQ(1, delegate->on_data_read_count());
   EXPECT_EQ(0, delegate->on_data_sent_count());
   EXPECT_EQ(kProtoHTTP2, delegate->GetProtocol());
   EXPECT_EQ(CountWriteBytes(writes, arraysize(writes)),
             delegate->GetTotalSentBytes());
   EXPECT_EQ(CountReadBytes(reads, arraysize(reads)),
             delegate->GetTotalReceivedBytes());
 }
 
-TEST_F(BidirectionalStreamTest, TestContainFullBytes) {
+// Tests that the NetLog contains correct entries.
+TEST_F(BidirectionalStreamTest, TestNetLogContainEntries) {
   BufferedSpdyFramer framer(spdy_util_.spdy_version());
 
   std::unique_ptr<SpdySerializedFrame> req(spdy_util_.ConstructSpdyPost(
       "https://www.example.org", 1, kBodyDataSize * 3, LOWEST, nullptr, 0));
   std::unique_ptr<SpdySerializedFrame> data_frame(
       framer.CreateDataFrame(1, kBodyData, kBodyDataSize, DATA_FLAG_FIN));
   MockWrite writes[] = {
       CreateMockWrite(*req, 0), CreateMockWrite(*data_frame, 3),
   };
 
   std::unique_ptr<SpdySerializedFrame> resp(
       spdy_util_.ConstructSpdyGetSynReply(nullptr, 0, 1));
   std::unique_ptr<SpdySerializedFrame> response_body_frame1(
       spdy_util_.ConstructSpdyBodyFrame(1, false));
   std::unique_ptr<SpdySerializedFrame> response_body_frame2(
-      spdy_util_.ConstructSpdyBodyFrame(1, true));
+      spdy_util_.ConstructSpdyBodyFrame(1, false));
+
+  SpdyHeaderBlock trailers;
+  trailers["foo"] = "bar";
+  std::unique_ptr<SpdySerializedFrame> response_trailers(
+      spdy_util_.ConstructSpdyResponseHeaders(1, trailers, true));
 
   MockRead reads[] = {
       CreateMockRead(*resp, 1),
       MockRead(ASYNC, ERR_IO_PENDING, 2),  // Force a pause.
       CreateMockRead(*response_body_frame1, 4),
       MockRead(ASYNC, ERR_IO_PENDING, 5),  // Force a pause.
       CreateMockRead(*response_body_frame2, 6),
-      MockRead(ASYNC, 0, 7),
+      CreateMockRead(*response_trailers, 7),
+      MockRead(ASYNC, 0, 8),
   };
 
   HostPortPair host_port_pair("www.example.org", 443);
   SpdySessionKey key(host_port_pair, ProxyServer::Direct(),
                      PRIVACY_MODE_DISABLED);
   InitSession(reads, arraysize(reads), writes, arraysize(writes), key);
 
   std::unique_ptr<BidirectionalStreamRequestInfo> request_info(
       new BidirectionalStreamRequestInfo);
   request_info->method = "POST";
@@ skipping 33 matching lines @@
   sequenced_data_->Resume();
   base::RunLoop().RunUntilIdle();
   // All data has been delivered, and OnClosed() has been invoked.
   // Read now, and it should complete synchronously.
   rv = delegate->ReadData();
   EXPECT_EQ(kUploadDataSize, rv);
   EXPECT_EQ("200", delegate->response_headers().find(":status")->second);
   EXPECT_EQ(1, delegate->on_data_read_count());
   EXPECT_EQ(1, delegate->on_data_sent_count());
   EXPECT_EQ(kProtoHTTP2, delegate->GetProtocol());
+  EXPECT_EQ("bar", delegate->trailers().find("foo")->second);
   EXPECT_EQ(CountWriteBytes(writes, arraysize(writes)),
             delegate->GetTotalSentBytes());
   EXPECT_EQ(CountReadBytes(reads, arraysize(reads)),
             delegate->GetTotalReceivedBytes());
 
+  // Destroy the delegate will destroy the stream, so we can get an end event
+  // for BIDIRECTIONAL_STREAM_ALIVE.
+  delegate.reset();
   TestNetLogEntry::List entries;
   net_log_.GetEntries(&entries);
+  size_t index = ExpectLogContainsSomewhere(
+      entries, 0, NetLog::TYPE_BIDIRECTIONAL_STREAM_ALIVE, NetLog::PHASE_BEGIN);
+  // Headers received should happen after BIDIRECTIONAL_STREAM_ALIVE.
+  index = ExpectLogContainsSomewhere(
+      entries, index, NetLog::TYPE_BIDIRECTIONAL_STREAM_RECV_HEADERS,
+      NetLog::PHASE_NONE);
+  // Trailers received should happen after headers received. It might happen
+  // before the reads complete.
+  ExpectLogContainsSomewhere(entries, index,
+                             NetLog::TYPE_BIDIRECTIONAL_STREAM_RECV_TRAILERS,
+                             NetLog::PHASE_NONE);
   // Sent bytes. Sending data is always asynchronous.
-  size_t index = ExpectLogContainsSomewhere(
-      entries, 0, NetLog::TYPE_BIDIRECTIONAL_STREAM_BYTES_SENT,
+  index = ExpectLogContainsSomewhere(
+      entries, index, NetLog::TYPE_BIDIRECTIONAL_STREAM_BYTES_SENT,
       NetLog::PHASE_NONE);
   TestNetLogEntry entry = entries[index];
   EXPECT_EQ(NetLog::SOURCE_BIDIRECTIONAL_STREAM, entry.source.type);
   // Received bytes for asynchronous read.
   index = ExpectLogContainsSomewhere(
       entries, index, NetLog::TYPE_BIDIRECTIONAL_STREAM_BYTES_RECEIVED,
       NetLog::PHASE_NONE);
   entry = entries[index];
   EXPECT_EQ(NetLog::SOURCE_BIDIRECTIONAL_STREAM, entry.source.type);
   // Received bytes for synchronous read.
   index = ExpectLogContainsSomewhere(
       entries, index, NetLog::TYPE_BIDIRECTIONAL_STREAM_BYTES_RECEIVED,
       NetLog::PHASE_NONE);
   entry = entries[index];
   EXPECT_EQ(NetLog::SOURCE_BIDIRECTIONAL_STREAM, entry.source.type);
+  ExpectLogContainsSomewhere(entries, index,
+                             NetLog::TYPE_BIDIRECTIONAL_STREAM_ALIVE,
+                             NetLog::PHASE_END);
 }
 
 TEST_F(BidirectionalStreamTest, TestInterleaveReadDataAndSendData) {
   BufferedSpdyFramer framer(spdy_util_.spdy_version());
 
   std::unique_ptr<SpdySerializedFrame> req(spdy_util_.ConstructSpdyPost(
       "https://www.example.org", 1, kBodyDataSize * 3, LOWEST, nullptr, 0));
   std::unique_ptr<SpdySerializedFrame> data_frame1(
       framer.CreateDataFrame(1, kBodyData, kBodyDataSize, DATA_FLAG_NONE));
   std::unique_ptr<SpdySerializedFrame> data_frame2(
@@ skipping 324 matching lines @@
   };
 
   const char* const kExtraResponseHeaders[] = {"header-name", "header-value"};
 
   std::unique_ptr<SpdySerializedFrame> resp(
       spdy_util_.ConstructSpdyGetSynReply(kExtraResponseHeaders, 1, 1));
 
   std::unique_ptr<SpdySerializedFrame> body_frame(
       spdy_util_.ConstructSpdyBodyFrame(1, false));
 
-  SpdyHeaderBlock late_headers;
-  late_headers["foo"] = "bar";
-  std::unique_ptr<SpdySerializedFrame> trailers(
-      spdy_util_.ConstructSpdyResponseHeaders(1, late_headers, true));
+  SpdyHeaderBlock trailers;
+  trailers["foo"] = "bar";
+  std::unique_ptr<SpdySerializedFrame> response_trailers(
+      spdy_util_.ConstructSpdyResponseHeaders(1, trailers, true));
 
   MockRead reads[] = {
-      CreateMockRead(*resp, 1),           CreateMockRead(*body_frame, 2),
-      CreateMockRead(*body_frame, 3),     CreateMockRead(*body_frame, 4),
+      CreateMockRead(*resp, 1),
+      CreateMockRead(*body_frame, 2),
+      CreateMockRead(*body_frame, 3),
+      CreateMockRead(*body_frame, 4),
       MockRead(ASYNC, ERR_IO_PENDING, 5),  // Force a pause.
-      CreateMockRead(*trailers, 6),       MockRead(SYNCHRONOUS, 0, 7),
+      CreateMockRead(*response_trailers, 6),
+      MockRead(SYNCHRONOUS, 0, 7),
   };
 
   HostPortPair host_port_pair("www.example.org", 443);
   SpdySessionKey key(host_port_pair, ProxyServer::Direct(),
                      PRIVACY_MODE_DISABLED);
   InitSession(reads, arraysize(reads), writes, arraysize(writes), key);
 
   scoped_refptr<IOBuffer> read_buffer(new IOBuffer(kReadBufferSize));
   MockTimer* timer = new MockTimer();
   std::unique_ptr<TestDelegateBase> delegate(new TestDelegateBase(
@@ skipping 351 matching lines @@
   };
 
   const char* const kExtraResponseHeaders[] = {"header-name", "header-value"};
 
   std::unique_ptr<SpdySerializedFrame> resp(
       spdy_util_.ConstructSpdyGetSynReply(kExtraResponseHeaders, 1, 1));
 
   std::unique_ptr<SpdySerializedFrame> response_body_frame(
       spdy_util_.ConstructSpdyBodyFrame(1, false));
 
-  SpdyHeaderBlock late_headers;
-  late_headers["foo"] = "bar";
-  std::unique_ptr<SpdySerializedFrame> trailers(
-      spdy_util_.ConstructSpdyResponseHeaders(1, late_headers, true));
+  SpdyHeaderBlock trailers;
+  trailers["foo"] = "bar";
+  std::unique_ptr<SpdySerializedFrame> response_trailers(
+      spdy_util_.ConstructSpdyResponseHeaders(1, trailers, true));
 
   MockRead reads[] = {
       CreateMockRead(*resp, 1), CreateMockRead(*response_body_frame, 2),
-      CreateMockRead(*trailers, 3), MockRead(ASYNC, 0, 5),
+      CreateMockRead(*response_trailers, 3), MockRead(ASYNC, 0, 5),
   };
 
   HostPortPair host_port_pair("www.example.org", 443);
   SpdySessionKey key(host_port_pair, ProxyServer::Direct(),
                      PRIVACY_MODE_DISABLED);
   InitSession(reads, arraysize(reads), writes, arraysize(writes), key);
 
   std::unique_ptr<BidirectionalStreamRequestInfo> request_info(
       new BidirectionalStreamRequestInfo);
   request_info->method = "GET";
@@ skipping 143 matching lines @@
   AlternativeServiceVector alternative_service_vector =
       http_session_->http_server_properties()->GetAlternativeServices(server);
   ASSERT_EQ(1u, alternative_service_vector.size());
   EXPECT_EQ(AlternateProtocolFromNextProto(kProtoQUIC1SPDY3),
             alternative_service_vector[0].protocol);
   EXPECT_EQ("www.example.org", alternative_service_vector[0].host);
   EXPECT_EQ(443, alternative_service_vector[0].port);
 }
 
 }  // namespace net