Add ongoing events to net-export log when logging starts

components/net_log/net_log_file_writer_unittest.cc

Index: components/net_log/net_log_file_writer_unittest.cc
diff --git a/components/net_log/net_log_file_writer_unittest.cc b/components/net_log/net_log_file_writer_unittest.cc
index bca94fb5843021f83177173007bab2b79b9795cb..a7e2778da964326dd5390a30a5e911e26371e8b2 100644
--- a/components/net_log/net_log_file_writer_unittest.cc
+++ b/components/net_log/net_log_file_writer_unittest.cc
@@ -46,6 +46,7 @@ const char kCaptureModeIncludeSocketBytesString[] = "LOG_BYTES";
 const char kStateUninitializedString[] = "UNINITIALIZED";
 const char kStateInitializingString[] = "INITIALIZING";
 const char kStateNotLoggingString[] = "NOT_LOGGING";
+const char kStateStartingLogString[] = "STARTING_LOG";
 const char kStateLoggingString[] = "LOGGING";
 const char kStateStoppingLogString[] = "STOPPING_LOG";
 }  // namespace
@@ -180,6 +181,24 @@ void SetUpTestContextGetterWithQuicTimeoutInfo(
       base::ThreadTaskRunnerHandle::Get(), std::move(context));
 }
 
+void SetUpTestContextGetterWithRequest(
+    net::NetLog* net_log,
+    base::StringPiece request_url,
+    net::URLRequest::Delegate* delegate,
+    scoped_refptr<net::TestURLRequestContextGetter>* context_getter,
+    std::unique_ptr<net::URLRequest>* request) {
+  std::unique_ptr<net::TestURLRequestContext> context =

[eroman, 2017/02/24 00:17:38]

[optional] My preference is to use "auto" with MakeUnique

[wangyix1, 2017/02/24 00:58:07]

Done.

+      base::MakeUnique<net::TestURLRequestContext>(true);
+  context->set_net_log(net_log);
+  context->Init();
+
+  *request = context->CreateRequest(GURL(request_url), net::IDLE, delegate);

[eroman, 2017/02/24 00:17:38]

[optional] I would suggest making |request_url| be of type |const GURL&| instead
of StringPiece, especially given that it is used with base::Bind().

(It is possible with StringPiece to end up with invalid pointers by the time the
task runs, since it doesn't own the memory).

[wangyix1, 2017/02/24 00:58:08]

Done.

+  (*request)->Start();
+
+  *context_getter = new net::TestURLRequestContextGetter(
+      base::ThreadTaskRunnerHandle::Get(), std::move(context));
+}
+
 // An implementation of NetLogFileWriter::StateObserver that allows waiting
 // until it's notified of a new state.
 class TestStateObserver : public NetLogFileWriter::StateObserver {
@@ -231,6 +250,9 @@ class TestFilePathCallback {
 
 class NetLogFileWriterTest : public ::testing::Test {
  public:
+  using URLRequestContextGetterList =
+      std::vector<scoped_refptr<net::URLRequestContextGetter>>;
+
   NetLogFileWriterTest()
       : net_log_(base::FilePath(),
                  net::NetLogCaptureMode::Default(),
@@ -308,16 +330,17 @@ class NetLogFileWriterTest : public ::testing::Test {
 
   // If |custom_log_path| is empty path, |net_log_file_writer_| will use its
   // default log path, which is cached in |default_log_path_|.
-  WARN_UNUSED_RESULT ::testing::AssertionResult StartThenVerifyNewState(
+  WARN_UNUSED_RESULT::testing::AssertionResult StartThenVerifyNewState(
       const base::FilePath& custom_log_path,
       net::NetLogCaptureMode capture_mode,
-      const std::string& expected_capture_mode_string) {
-    net_log_file_writer_.StartNetLog(custom_log_path, capture_mode);
+      const std::string& expected_capture_mode_string,
+      const URLRequestContextGetterList& context_getters) {
+    net_log_file_writer_.StartNetLog(custom_log_path, capture_mode,
+                                     context_getters);
     std::unique_ptr<base::DictionaryValue> state =
         test_state_observer_.WaitForNewState();
     ::testing::AssertionResult result =
-        VerifyState(std::move(state), kStateLoggingString, true, true,
-                    expected_capture_mode_string);
+        VerifyState(std::move(state), kStateStartingLogString);
     if (!result) {
       return ::testing::AssertionFailure()
              << "First state after StartNetLog() does not match expected:"
@@ -325,6 +348,16 @@ class NetLogFileWriterTest : public ::testing::Test {
              << result.message();
     }
 
+    state = test_state_observer_.WaitForNewState();
+    result = VerifyState(std::move(state), kStateLoggingString, true, true,
+                         expected_capture_mode_string);
+    if (!result) {
+      return ::testing::AssertionFailure()
+             << "Second state after StartNetLog() does not match expected:"
+             << std::endl
+             << result.message();
+    }
+
     // Make sure GetFilePath() returns empty path when logging.
     base::FilePath actual_log_path = FileWriterGetFilePathToCompletedLog();
     if (!actual_log_path.empty()) {
@@ -463,16 +496,16 @@ TEST_F(NetLogFileWriterTest, StartAndStopWithAllCaptureModes) {
   for (int i = 0; i < 3; ++i) {
     // StartNetLog(), should result in state change.
     ASSERT_TRUE(StartThenVerifyNewState(base::FilePath(), capture_modes[i],
-                                        capture_mode_strings[i]));
+                                        capture_mode_strings[i], {}));
 
     // Calling StartNetLog() again should be a no-op. Try doing StartNetLog()
     // with various capture modes; they should all be ignored and result in no
     // state change.
-    net_log_file_writer_.StartNetLog(base::FilePath(), capture_modes[i]);
+    net_log_file_writer_.StartNetLog(base::FilePath(), capture_modes[i], {});
     net_log_file_writer_.StartNetLog(base::FilePath(),
-                                     capture_modes[(i + 1) % 3]);
+                                     capture_modes[(i + 1) % 3], {});
     net_log_file_writer_.StartNetLog(base::FilePath(),
-                                     capture_modes[(i + 2) % 3]);
+                                     capture_modes[(i + 2) % 3], {});
 
     // StopNetLog(), should result in state change. The capture mode should
     // match that of the first StartNetLog() call (called by
@@ -487,7 +520,7 @@ TEST_F(NetLogFileWriterTest, StartAndStopWithAllCaptureModes) {
   // Start and stop one more time just to make sure the last StopNetLog() call
   // was properly ignored and left |net_log_file_writer_| in a valid state.
   ASSERT_TRUE(StartThenVerifyNewState(base::FilePath(), capture_modes[0],
-                                      capture_mode_strings[0]));
+                                      capture_mode_strings[0], {}));
 
   ASSERT_TRUE(StopThenVerifyNewStateAndFile(base::FilePath(), nullptr, nullptr,
                                             capture_mode_strings[0]));
@@ -500,7 +533,7 @@ TEST_F(NetLogFileWriterTest, StartClearsFile) {
 
   ASSERT_TRUE(StartThenVerifyNewState(base::FilePath(),
                                       net::NetLogCaptureMode::Default(),
-                                      kCaptureModeDefaultString));
+                                      kCaptureModeDefaultString, {}));
 
   ASSERT_TRUE(StopThenVerifyNewStateAndFile(base::FilePath(), nullptr, nullptr,
                                             kCaptureModeDefaultString));
@@ -521,7 +554,7 @@ TEST_F(NetLogFileWriterTest, StartClearsFile) {
   // before adding the junk data.
   ASSERT_TRUE(StartThenVerifyNewState(base::FilePath(),
                                       net::NetLogCaptureMode::Default(),
-                                      kCaptureModeDefaultString));
+                                      kCaptureModeDefaultString, {}));
 
   ASSERT_TRUE(StopThenVerifyNewStateAndFile(base::FilePath(), nullptr, nullptr,
                                             kCaptureModeDefaultString));
@@ -539,7 +572,7 @@ TEST_F(NetLogFileWriterTest, AddEvent) {
 
   ASSERT_TRUE(StartThenVerifyNewState(base::FilePath(),
                                       net::NetLogCaptureMode::Default(),
-                                      kCaptureModeDefaultString));
+                                      kCaptureModeDefaultString, {}));
 
   ASSERT_TRUE(StopThenVerifyNewStateAndFile(base::FilePath(), nullptr, nullptr,
                                             kCaptureModeDefaultString));
@@ -550,7 +583,7 @@ TEST_F(NetLogFileWriterTest, AddEvent) {
 
   ASSERT_TRUE(StartThenVerifyNewState(base::FilePath(),
                                       net::NetLogCaptureMode::Default(),
-                                      kCaptureModeDefaultString));
+                                      kCaptureModeDefaultString, {}));
 
   net_log_.AddGlobalEntry(net::NetLogEventType::CANCELLED);
 
@@ -577,7 +610,7 @@ TEST_F(NetLogFileWriterTest, AddEventCustomPath) {
 
   ASSERT_TRUE(StartThenVerifyNewState(custom_log_path,
                                       net::NetLogCaptureMode::Default(),
-                                      kCaptureModeDefaultString));
+                                      kCaptureModeDefaultString, {}));
 
   ASSERT_TRUE(StopThenVerifyNewStateAndFile(custom_log_path, nullptr, nullptr,
                                             kCaptureModeDefaultString));
@@ -588,7 +621,7 @@ TEST_F(NetLogFileWriterTest, AddEventCustomPath) {
 
   ASSERT_TRUE(StartThenVerifyNewState(custom_log_path,
                                       net::NetLogCaptureMode::Default(),
-                                      kCaptureModeDefaultString));
+                                      kCaptureModeDefaultString, {}));
 
   net_log_.AddGlobalEntry(net::NetLogEventType::CANCELLED);
 
@@ -623,7 +656,7 @@ TEST_F(NetLogFileWriterTest, StopWithPolledDataAndContextGetter) {
 
   ASSERT_TRUE(StartThenVerifyNewState(base::FilePath(),
                                       net::NetLogCaptureMode::Default(),
-                                      kCaptureModeDefaultString));
+                                      kCaptureModeDefaultString, {}));
 
   ASSERT_TRUE(StopThenVerifyNewStateAndFile(
       base::FilePath(), std::move(dummy_polled_data), context_getter,
@@ -652,6 +685,52 @@ TEST_F(NetLogFileWriterTest, StopWithPolledDataAndContextGetter) {
   EXPECT_EQ(kDummyQuicParam, timeout);
 }
 
+TEST_F(NetLogFileWriterTest, StartWithContextGetters) {

[eroman, 2017/02/24 00:17:38]

Thanks for adding the test!

[wangyix1, 2017/02/24 00:58:08]

Acknowledged.

+  ASSERT_TRUE(InitializeThenVerifyNewState(true, false));
+
+  // Create test context getter and request on |net_thread_| and wait for it to
+  // finish.
+  const std::string kDummyUrl = "blah:blah";
+  scoped_refptr<net::TestURLRequestContextGetter> context_getter;
+  std::unique_ptr<net::URLRequest> request;
+  net::TestDelegate delegate;
+  delegate.set_quit_on_complete(false);
+
+  net::TestClosure init_done;
+  net_thread_.task_runner()->PostTaskAndReply(
+      FROM_HERE, base::Bind(&SetUpTestContextGetterWithRequest, &net_log_,
+                            kDummyUrl, &delegate, &context_getter, &request),
+      init_done.closure());
+  init_done.WaitForResult();
+
+  ASSERT_TRUE(StartThenVerifyNewState(
+      base::FilePath(), net::NetLogCaptureMode::Default(),
+      kCaptureModeDefaultString, {context_getter}));
+
+  ASSERT_TRUE(StopThenVerifyNewStateAndFile(base::FilePath(), nullptr, nullptr,
+                                            kCaptureModeDefaultString));
+
+  // Read events from log file.
+  std::unique_ptr<base::DictionaryValue> root;
+  ASSERT_TRUE(ReadCompleteLogFile(default_log_path_, &root));
+  base::ListValue* events;
+  ASSERT_TRUE(root->GetList("events", &events));
+
+  // Check there is at least one event as a result of the ongoing request.
+  EXPECT_GE(events->GetSize(), 1u);
+
+  // Check the URL in the params of the first event.
+  base::DictionaryValue* event;
+  EXPECT_TRUE(events->GetDictionary(0, &event));
+  base::DictionaryValue* event_params;
+  EXPECT_TRUE(event->GetDictionary("params", &event_params));
+  std::string event_url;
+  EXPECT_TRUE(event_params->GetString("url", &event_url));
+  EXPECT_EQ(kDummyUrl, event_url);
+
+  net_thread_.task_runner()->DeleteSoon(FROM_HERE, request.release());
+}
+
 TEST_F(NetLogFileWriterTest, ReceiveStartWhileInitializing) {
   // Trigger initialization of |net_log_file_writer_|.
   net_log_file_writer_.Initialize(file_thread_.task_runner(),
@@ -663,7 +742,7 @@ TEST_F(NetLogFileWriterTest, ReceiveStartWhileInitializing) {
   // before |net_log_file_writer_| finishes initialization, which means this
   // should be a no-op.
   net_log_file_writer_.StartNetLog(base::FilePath(),
-                                   net::NetLogCaptureMode::Default());
+                                   net::NetLogCaptureMode::Default(), {});
 
   // Now run the main message loop. Make sure StartNetLog() was ignored by
   // checking that the next two states are "initializing" followed by
@@ -682,7 +761,7 @@ TEST_F(NetLogFileWriterTest, ReceiveStartWhileStoppingLog) {
   // Call StartNetLog() on |net_log_file_writer_| and wait for the state change.
   ASSERT_TRUE(StartThenVerifyNewState(
       base::FilePath(), net::NetLogCaptureMode::IncludeSocketBytes(),
-      kCaptureModeIncludeSocketBytesString));
+      kCaptureModeIncludeSocketBytesString, {}));
 
   // Tell |net_log_file_writer_| to stop logging.
   net_log_file_writer_.StopNetLog(nullptr, nullptr);
@@ -693,7 +772,7 @@ TEST_F(NetLogFileWriterTest, ReceiveStartWhileStoppingLog) {
   // |net_log_file_writer_| finishes stopping, which means this should be a
   // no-op.
   net_log_file_writer_.StartNetLog(base::FilePath(),
-                                   net::NetLogCaptureMode::Default());
+                                   net::NetLogCaptureMode::Default(), {});
 
   // Now run the main message loop. Make sure the last StartNetLog() was
   // ignored by checking that the next two states are "stopping-log" followed by