Reenable the WebRTC EventLog API Tests.

chrome/browser/extensions/api/webrtc_logging_private/webrtc_event_log_apitest.cc

Index: chrome/browser/extensions/api/webrtc_logging_private/webrtc_event_log_apitest.cc
diff --git a/chrome/browser/extensions/api/webrtc_logging_private/webrtc_event_log_apitest.cc b/chrome/browser/extensions/api/webrtc_logging_private/webrtc_event_log_apitest.cc
index df04767c80b4ce795de6b068d0b481c385830aa9..22d19e9f666d412ba52737e2ebea9398862cfdc9 100644
--- a/chrome/browser/extensions/api/webrtc_logging_private/webrtc_event_log_apitest.cc
+++ b/chrome/browser/extensions/api/webrtc_logging_private/webrtc_event_log_apitest.cc
@@ -38,15 +38,14 @@ namespace utils = extension_function_test_utils;
 namespace {
 
 // Get the expected EventLog file name. The name will be
-// <temporary path>.<render process id>.event_log.<consumer id>, for example
+// <temporary path>.<render process id>.<peer connection id>, for example
 // /tmp/.org.chromium.Chromium.vsygNQ/dnFW8ch/Default/WebRTC
-// Logs/WebRtcEventLog.1.29113.event_log.1
+// Logs/WebRtcEventLog.1.6.1
 base::FilePath GetExpectedEventLogFileName(const base::FilePath& base_file,
                                            int render_process_id) {
-  static const int kExpectedConsumerId = 1;
+  static const int kExpectedPeerConnectionId = 1;
   return base_file.AddExtension(IntToStringType(render_process_id))
-      .AddExtension(FILE_PATH_LITERAL("event_log"))
-      .AddExtension(IntToStringType(kExpectedConsumerId));
+      .AddExtension(IntToStringType(kExpectedPeerConnectionId));
 }
 
 static const char kMainWebrtcTestHtmlPage[] = "/webrtc/webrtc_jsep01_test.html";
@@ -107,9 +106,7 @@ class WebrtcEventLogApiTest : public WebRtcTestBase {
 
 }  // namespace
 
-// TODO(ivoc): Reenable when the event log functionality in Chrome is updated.
-IN_PROC_BROWSER_TEST_F(WebrtcEventLogApiTest,
-                       DISABLED_TestStartStopWebRtcEventLogging) {
+IN_PROC_BROWSER_TEST_F(WebrtcEventLogApiTest, TestStartStopWebRtcEventLogging) {
   ASSERT_TRUE(embedded_test_server()->Start());
 
   content::WebContents* left_tab =
@@ -178,12 +175,14 @@ IN_PROC_BROWSER_TEST_F(WebrtcEventLogApiTest,
   EXPECT_EQ(file_name_start, file_name_stop);
 
   // Check that the file exists and is non-empty.
-  base::ProcessId render_process_id =
-      base::GetProcId(left_tab->GetRenderProcessHost()->GetHandle());
-  EXPECT_NE(render_process_id, base::kNullProcessId);
+  content::RenderProcessHost* render_process_host =
+      left_tab->GetRenderProcessHost();
+  ASSERT_NE(render_process_host, nullptr);
+  int render_process_id = render_process_host->GetID();
   base::FilePath full_file_name =
       GetExpectedEventLogFileName(file_name_stop, render_process_id);
   int64_t file_size = 0;
+  int timeout_counter = 0;
   while (!(base::PathExists(full_file_name) &&
            base::GetFileSize(full_file_name, &file_size) && file_size > 0)) {
     // This should normally not happen, but is here to prevent the test
@@ -191,6 +190,10 @@ IN_PROC_BROWSER_TEST_F(WebrtcEventLogApiTest,
     // /webrtc/webrtc_jsep01_test.html changes.
     VLOG(1) << "Waiting for logfile to become available...";
     base::PlatformThread::Sleep(base::TimeDelta::FromMilliseconds(100));

[asargent_no_longer_on_chrome, 2016/07/19 16:29:54]

It's usually problematic to use sleep calls inside tests. Can you switch to
using base::FilePathWatcher instead here?

[Ivo-OOO until feb 6, 2016/07/20 12:12:33]

Good idea, it looks like FilePathWatcher would be a good fit here, but I'm
worried that the test can get stuck here if the file for some reason doesn't get
created (which actually happened recently). Do you know how that case would be
handled with FilePathWatcher? Or is it okay if tests can get stuck?

[asargent_no_longer_on_chrome, 2016/07/20 17:19:12]

I think you can just use a base::RunLoop with a helper class that contains the
FilePathWatcher - the RunLoop will automatically get quit if the test times out.
Something like the following:

class MyWatcher {
 public:
  MyWatcher(const base::FilePath& path) : found_(false), path_(path) {}

  
  bool Start() {
    if (base::PathExists(path_)) {
      found_ = true;
      return true;
    } else {
      return watcher_.Watch(path_, false /* recursive */, 
                            base::Bind(this, &Watcher::Callback));
    }
  }

  // Returns true if |path_| became available.
  bool Wait() {
    if (!found_) {
      run_loop_.Run();
    }
    return found_;
  }  

  // implements FilePathWatcher::Callback
  void Callback(const FilePath& path, bool error) {
    EXPECT_EQ(path, path_);
    if (!error)
      found_ = true;
    run_loop_.Quit();
  }
  
 
 private:
  base::RunLoop run_loop_;
  bool found_;
  base::FilePath path_;
  base::FilePathWatcher watcher_;
};


then you can use this in your test like this:

MyWatcher watcher(full_file_name);
ASSERT_TRUE(watcher.Start()) << "error watching for " << full_file_name;

// do stuff that can result in logfile becoming available

ASSERT_TRUE(watcher.WaitForFile());


Then the test will either abort on timeouts, or continue from this point knowing
the file exists.

One problem with all this is that the file might not have the contents you want
yet - I think the MyWatcher Wait method might return as soon as the file gets
created, but there might not be a guarantee that it has any contents yet. To get
around this, the easiest thing to do might be to add some more explicit Watcher
interface from the code which writes the log in the first place, which gets
triggered once it is done writing the log file.

If that isn't feasible, you could get fancier with your use of FilePathWatcher
to wait for contents to be written into the file, but that seems inherently
error prone (at least if you care about how many bytes are written or whether
they have specific contents), and also runs into the problem that on Mac OSX it
sounds like FilePathWatcher only fires for file creation/deletion but not
contents changes. 

[Ivo-OOO until feb 6, 2016/07/21 15:20:55]

Wow, thanks for the detailed reply and code, very helpful! I made the change
like you suggested. 
I don't think we care much about the actual file contents in this test (we have
plenty of other tests inside of WebRTC for that), so just checking that the file
was created and that it contains something should be fine.

+    if (timeout_counter++ >= 50) {
+      VLOG(1) << "Giving up on waiting for logfile.";
+      break;
+    }
   }
   ASSERT_TRUE(base::PathExists(full_file_name));
   EXPECT_TRUE(base::GetFileSize(full_file_name, &file_size));
@@ -200,9 +203,8 @@ IN_PROC_BROWSER_TEST_F(WebrtcEventLogApiTest,
   base::DeleteFile(full_file_name, false);
 }
 
-// TODO(ivoc): Reenable when the event log functionality in Chrome is updated.
 IN_PROC_BROWSER_TEST_F(WebrtcEventLogApiTest,
-                       DISABLED_TestStartTimedWebRtcEventLogging) {
+                       TestStartTimedWebRtcEventLogging) {
   ASSERT_TRUE(embedded_test_server()->Start());
 
   content::WebContents* left_tab =
@@ -252,12 +254,14 @@ IN_PROC_BROWSER_TEST_F(WebrtcEventLogApiTest,
 
   // The log has stopped automatically. Check that the file exists and is
   // non-empty.
-  base::ProcessId render_process_id =
-      base::GetProcId(left_tab->GetRenderProcessHost()->GetHandle());
-  EXPECT_NE(render_process_id, base::kNullProcessId);
+  content::RenderProcessHost* render_process_host =
+      left_tab->GetRenderProcessHost();
+  ASSERT_NE(render_process_host, nullptr);
+  int render_process_id = render_process_host->GetID();
   base::FilePath full_file_name =
       GetExpectedEventLogFileName(file_name_start, render_process_id);
   int64_t file_size = 0;
+  int timeout_counter = 0;
   while (!(base::PathExists(full_file_name) &&
            base::GetFileSize(full_file_name, &file_size) && file_size > 0)) {
     // This should normally not happen, but is here to prevent the test
@@ -265,6 +269,10 @@ IN_PROC_BROWSER_TEST_F(WebrtcEventLogApiTest,
     // /webrtc/webrtc_jsep01_test.html changes.
     VLOG(1) << "Waiting for logfile to become available...";
     base::PlatformThread::Sleep(base::TimeDelta::FromMilliseconds(100));

[asargent_no_longer_on_chrome, 2016/07/19 16:29:54]

same thing here

+    if (timeout_counter++ >= 50) {
+      VLOG(1) << "Giving up on waiting for logfile.";
+      break;
+    }
   }
   ASSERT_TRUE(base::PathExists(full_file_name));
   EXPECT_TRUE(base::GetFileSize(full_file_name, &file_size));