Enable background tracing proto output by default.

Fix tracing delegate browser tests to use proto output.
Re enable tests with closed, archived or very old bugs, to see if it
is still flaky.

Fix trace event data source to not expect perfetto to wait for
stop acks.

The experiment configs are updated to disable this experiment where
needed, the system will upload traces to uma service by default
instead of JSON.

Change-Id: Id3acb1aa3cdedbcd07c41e18fd0bc66a3cdc1129
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2088213
Commit-Queue: ssid <ssid@chromium.org>
Reviewed-by: oysteine <oysteine@chromium.org>
Reviewed-by: Alexander Yashkin <a-v-y@yandex-team.ru>
Cr-Commit-Position: refs/heads/master@{#749278}

chrome/browser/tracing/chrome_tracing_delegate_browsertest.cc

@@ -23,7 +23,9 @@
 #include "content/public/browser/background_tracing_manager.h"
 #include "content/public/browser/browser_task_traits.h"
 #include "content/public/browser/browser_thread.h"
+#include "content/public/browser/tracing_controller.h"
 #include "content/public/test/test_utils.h"
+#include "services/tracing/public/cpp/tracing_features.h"
 
 namespace {
 
@@ -39,14 +41,12 @@ class ChromeTracingDelegateBrowserTest : public InProcessBrowserTest {
     PrefService* local_state = g_browser_process->local_state();
     DCHECK(local_state);
     local_state->SetBoolean(metrics::prefs::kMetricsReportingEnabled, true);
+    content::TracingController::GetInstance();  // Create tracing agents.
   }
 #endif
 
   bool StartPreemptiveScenario(
-      const base::Closure& on_upload_callback,
       content::BackgroundTracingManager::DataFiltering data_filtering) {
-    on_upload_callback_ = on_upload_callback;
-
     base::DictionaryValue dict;
 
     dict.SetString("mode", "PREEMPTIVE_TRACING_MODE");
@@ -66,6 +66,7 @@ class ChromeTracingDelegateBrowserTest : public InProcessBrowserTest {
         content::BackgroundTracingConfig::FromDict(&dict));
 
     DCHECK(config);
+    wait_for_upload_ = std::make_unique<base::RunLoop>();
     content::BackgroundTracingManager::ReceiveCallback receive_callback =
         base::BindRepeating(&ChromeTracingDelegateBrowserTest::OnUpload,
                             base::Unretained(this));
@@ -89,6 +90,21 @@ class ChromeTracingDelegateBrowserTest : public InProcessBrowserTest {
         trigger_handle_, std::move(started_finalizing_callback));
   }
 
+  void WaitForUpload() {
+    if (base::FeatureList::IsEnabled(features::kBackgroundTracingProtoOutput)) {
+      while (!content::BackgroundTracingManager::GetInstance()
+                  ->HasTraceToUpload()) {
+        base::RunLoop().RunUntilIdle();
+      }
+      EXPECT_FALSE(content::BackgroundTracingManager::GetInstance()
+                       ->GetLatestTraceToUpload()
+                       .empty());
+      receive_count_++;
+    } else {
+      wait_for_upload_->Run();
+    }
+  }
+
   int get_receive_count() const { return receive_count_; }
   bool get_started_finalizations() const {
     return started_finalizations_count_;
@@ -106,7 +122,7 @@ class ChromeTracingDelegateBrowserTest : public InProcessBrowserTest {
     base::PostTask(FROM_HERE, {content::BrowserThread::UI},
                    base::BindOnce(std::move(done_callback), true));
     base::PostTask(FROM_HERE, {content::BrowserThread::UI},
-                   on_upload_callback_);
+                   wait_for_upload_->QuitClosure());
   }
 
   void OnStartedFinalizing(bool success) {
@@ -119,7 +135,7 @@ class ChromeTracingDelegateBrowserTest : public InProcessBrowserTest {
     }
   }
 
-  base::Closure on_upload_callback_;
+  std::unique_ptr<base::RunLoop> wait_for_upload_;
   base::Closure on_started_finalization_callback_;
   int receive_count_;
   int started_finalizations_count_;
@@ -129,15 +145,12 @@ class ChromeTracingDelegateBrowserTest : public InProcessBrowserTest {
 
 IN_PROC_BROWSER_TEST_F(ChromeTracingDelegateBrowserTest,
                        BackgroundTracingTimeThrottled) {
-  base::RunLoop wait_for_upload;
-
   EXPECT_TRUE(StartPreemptiveScenario(
-      wait_for_upload.QuitClosure(),
       content::BackgroundTracingManager::NO_DATA_FILTERING));
 
   TriggerPreemptiveScenario(base::Closure());
 
-  wait_for_upload.Run();
+  WaitForUpload();
 
   EXPECT_TRUE(get_receive_count() == 1);
 
@@ -156,28 +169,17 @@ IN_PROC_BROWSER_TEST_F(ChromeTracingDelegateBrowserTest,
   // We should not be able to start a new reactive scenario immediately after
   // a previous one gets uploaded.
   EXPECT_FALSE(StartPreemptiveScenario(
-      base::Closure(), content::BackgroundTracingManager::NO_DATA_FILTERING));
+      content::BackgroundTracingManager::NO_DATA_FILTERING));
 }
 
-// Flaky on Linux and Windows. See https://crbug.com/723933.
-#if defined(OS_LINUX) || defined(OS_WIN)
-#define MAYBE_BackgroundTracingThrottleTimeElapsed \
-  DISABLED_BackgroundTracingThrottleTimeElapsed
-#else
-#define MAYBE_BackgroundTracingThrottleTimeElapsed \
-  BackgroundTracingThrottleTimeElapsed
-#endif
 IN_PROC_BROWSER_TEST_F(ChromeTracingDelegateBrowserTest,
-                       MAYBE_BackgroundTracingThrottleTimeElapsed) {
-  base::RunLoop wait_for_upload;
-
+                       BackgroundTracingThrottleTimeElapsed) {
   EXPECT_TRUE(StartPreemptiveScenario(
-      wait_for_upload.QuitClosure(),
       content::BackgroundTracingManager::NO_DATA_FILTERING));
 
   TriggerPreemptiveScenario(base::Closure());
 
-  wait_for_upload.Run();
+  WaitForUpload();
 
   EXPECT_TRUE(get_receive_count() == 1);
 
@@ -194,7 +196,6 @@ IN_PROC_BROWSER_TEST_F(ChromeTracingDelegateBrowserTest,
   wait_for_abort.Run();
 
   EXPECT_FALSE(StartPreemptiveScenario(
-      base::RepeatingClosure(),
       content::BackgroundTracingManager::NO_DATA_FILTERING));
 
   // We move the last upload time to eight days in the past,
@@ -203,41 +204,25 @@ IN_PROC_BROWSER_TEST_F(ChromeTracingDelegateBrowserTest,
   local_state->SetInt64(prefs::kBackgroundTracingLastUpload,
                         new_upload_time.ToInternalValue());
   EXPECT_TRUE(StartPreemptiveScenario(
-      base::Closure(), content::BackgroundTracingManager::NO_DATA_FILTERING));
+      content::BackgroundTracingManager::NO_DATA_FILTERING));
 }
 
-#if defined(OS_MACOSX) && defined(ADDRESS_SANITIZER)
-// Flaky on ASAN on Mac. See https://crbug.com/674497.
-#define MAYBE_ExistingIncognitoSessionBlockingTraceStart \
-  DISABLED_ExistingIncognitoSessionBlockingTraceStart
-#else
-#define MAYBE_ExistingIncognitoSessionBlockingTraceStart \
-  ExistingIncognitoSessionBlockingTraceStart
-#endif
 // If we need a PII-stripped trace, any existing OTR session should block the
 // trace.
 IN_PROC_BROWSER_TEST_F(ChromeTracingDelegateBrowserTest,
-                       MAYBE_ExistingIncognitoSessionBlockingTraceStart) {
+                       ExistingIncognitoSessionBlockingTraceStart) {
   EXPECT_TRUE(chrome::ExecuteCommand(browser(), IDC_NEW_INCOGNITO_WINDOW));
   EXPECT_TRUE(BrowserList::IsIncognitoSessionActive());
   EXPECT_FALSE(StartPreemptiveScenario(
-      base::Closure(), content::BackgroundTracingManager::ANONYMIZE_DATA));
+      content::BackgroundTracingManager::ANONYMIZE_DATA));
 }
 
-#if defined(OS_MACOSX) && defined(ADDRESS_SANITIZER)
-// Flaky on ASAN on Mac. See https://crbug.com/674497.
-#define MAYBE_NewIncognitoSessionBlockingTraceFinalization \
-  DISABLED_NewIncognitoSessionBlockingTraceFinalization
-#else
-#define MAYBE_NewIncognitoSessionBlockingTraceFinalization \
-  NewIncognitoSessionBlockingTraceFinalization
-#endif
 // If we need a PII-stripped trace, any new OTR session during tracing should
 // block the finalization of the trace.
 IN_PROC_BROWSER_TEST_F(ChromeTracingDelegateBrowserTest,
-                       MAYBE_NewIncognitoSessionBlockingTraceFinalization) {
+                       NewIncognitoSessionBlockingTraceFinalization) {
   EXPECT_TRUE(StartPreemptiveScenario(
-      base::Closure(), content::BackgroundTracingManager::ANONYMIZE_DATA));
+      content::BackgroundTracingManager::ANONYMIZE_DATA));
 
   EXPECT_TRUE(chrome::ExecuteCommand(browser(), IDC_NEW_INCOGNITO_WINDOW));
   EXPECT_TRUE(BrowserList::IsIncognitoSessionActive());
@@ -312,9 +297,10 @@ IN_PROC_BROWSER_TEST_F(ChromeTracingDelegateBrowserTestOnStartup,
                         base::Time::Now().ToInternalValue());
 }
 
-// https://crbug.com/832981
+// https://crbug.com/832981: The test is reenabled to check if flakiness still
+// exists.
 IN_PROC_BROWSER_TEST_F(ChromeTracingDelegateBrowserTestOnStartup,
-                       DISABLED_StartupTracingThrottle) {
+                       StartupTracingThrottle) {
   // The startup scenario should *not* be started, since not enough
   // time has elapsed since the last upload (set in the PRE_ above).
   EXPECT_FALSE(

services/tracing/public/cpp/perfetto/trace_event_data_source.cc

@@ -469,12 +469,32 @@ void TraceEventDataSource::RegisterWithTraceLog() {
   is_enabled_ = true;
 }
 
-void TraceEventDataSource::UnregisterFromTraceLog() {
+void TraceEventDataSource::OnStopTracingDone() {
+  DCHECK_CALLED_ON_VALID_SEQUENCE(perfetto_sequence_checker_);
+
+  // WARNING: This function might never be called at the end of a tracing
+  // session. See comment in StartTracing() for more information.
+
+  // Unregister overrides.
   TraceLog::GetInstance()->SetAddTraceEventOverrides(nullptr, nullptr, nullptr);
+
+  base::OnceClosure task;
+  {
     base::AutoLock l(lock_);
     is_enabled_ = false;
+
+    // Check for any start or stop tracing pending task.
+    task = std::move(flush_complete_task_);
     flushing_trace_log_ = false;
-  DCHECK(!flush_complete_task_);
+
+    IncrementSessionIdOrClearStartupFlagWhileLocked();
+  }
+  if (stop_complete_callback_) {
+    std::move(stop_complete_callback_).Run();
+  }
+  if (task) {
+    std::move(task).Run();
+  }
 }
 
 // static
@@ -675,10 +695,17 @@ void TraceEventDataSource::StartTracing(
   {
     AutoLockWithDeferredTaskPosting l(lock_);
     if (flushing_trace_log_) {
-      DCHECK(!flush_complete_task_);
-      // Delay start tracing until flush is finished.
-      // Unretained is fine here because the producer will be valid till
-      // stop tracing is called and at stop this task will be cleared.
+      // Delay start tracing until flush is finished. Perfetto can call start
+      // while flushing if startup tracing (started by ourself) is cancelled, or
+      // when perfetto force aborts session without waiting for stop acks.
+      // |flush_complete_task_| will not be null here if perfetto calls start,
+      // stop and start again all while flushing trace log for a previous
+      // session, without waiting for stop complete callback for both. In all
+      // these cases it is safe to just drop the |flush_complete_callback_|,
+      // which is supposed to run OnStopTracingDone() and send stop ack to
+      // Perfetto, but Perfetto already ignored the ack and continued.
+      // Unretained is fine here because the producer will be valid till stop
+      // tracing is called and at stop this task will be cleared.
       flush_complete_task_ = base::BindOnce(
           &TraceEventDataSource::StartTracingInternal, base::Unretained(this),
           base::Unretained(producer), data_source_config);
@@ -771,12 +798,7 @@ void TraceEventDataSource::StopTracing(
         if (has_more_events) {
           return;
         }
-
-        data_source->UnregisterFromTraceLog();
-
-        if (data_source->stop_complete_callback_) {
-          std::move(data_source->stop_complete_callback_).Run();
-        }
+        data_source->OnStopTracingDone();
       };
 
   bool was_enabled = TraceLog::GetInstance()->IsEnabled();
@@ -792,9 +814,10 @@ void TraceEventDataSource::StopTracing(
     if (flush_complete_task_) {
       DCHECK(!producer_);
       // Skip start tracing task at this point if we still have not flushed
-      // trace log. We wouldn't be replacing a |flush_complete_task_| that is
-      // stop tracing callback task at any point, since perfetto will wait for
-      // the callback before starting next session.
+      // trace log. We would only replace a start tracing call here since the
+      // current StopTracing call should have a matching start call. The service
+      // never calls consecutive start or stop. It is ok to ignore the start
+      // here since the session has already ended, before we finished flushing.
       flush_complete_task_ =
           base::BindOnce(std::move(on_tracing_stopped_callback), this,
                          scoped_refptr<base::RefCountedString>(), false);

services/tracing/public/cpp/perfetto/trace_event_data_source.h

@@ -231,7 +231,7 @@ class COMPONENT_EXPORT(TRACING_CPP) TraceEventDataSource
       const perfetto::DataSourceConfig& data_source_config);
 
   void RegisterWithTraceLog();
-  void UnregisterFromTraceLog();
+  void OnStopTracingDone();
 
   std::unique_ptr<perfetto::TraceWriter> CreateTraceWriterLocked();
   TrackEventThreadLocalEventSink* CreateThreadLocalEventSink(

services/tracing/public/cpp/tracing_features.cc

@@ -22,13 +22,7 @@ namespace features {
 // Causes the BackgroundTracingManager to upload proto messages via UMA,
 // rather than JSON via the crash frontend.
 const base::Feature kBackgroundTracingProtoOutput{
-  "BackgroundTracingProtoOutput",
-#if defined(OS_ANDROID)
-      base::FEATURE_ENABLED_BY_DEFAULT
-#else
-      base::FEATURE_DISABLED_BY_DEFAULT
-#endif
-};
+    "BackgroundTracingProtoOutput", base::FEATURE_ENABLED_BY_DEFAULT};
 
 // Runs the tracing service as an in-process browser service.
 const base::Feature kTracingServiceInProcess {