arc: enable Android tracing in verified-boot mode

In verified-boot mode, ftrace trace_marker is not allowed for writting
due to security concern. As an altenative, we use a socket for processes in
Android to write trace events, and send back the trace data via Mojo
handle.

All change set includes:
- http://crrev.com/2400163003 (Chromium)
- http://ag/2028075 (Android system/core)
- http://ag/1738271 (Android device/google/cheets2)

BUG=653795
TEST=Run chrome://tracing and see events from Android.

Review-Url: https://codereview.chromium.org/2400163003
Cr-Commit-Position: refs/heads/master@{#468306}

chrome/browser/chromeos/arc/tracing/arc_tracing_bridge.cc

@@ -10,6 +10,7 @@
 #include "components/arc/arc_bridge_service.h"
 #include "components/arc/arc_service_manager.h"
 #include "content/public/browser/browser_thread.h"
+#include "mojo/public/cpp/system/platform_handle.h"
 
 namespace arc {
 
@@ -59,7 +60,7 @@ void ArcTracingBridge::OnCategoriesReady(
   // ignored when calling |StartTracing|.
   categories_.clear();
   for (const auto& category : categories) {
-    categories_.push_back({category, kCategoryPrefix + category});
+    categories_.emplace_back(Category{category, kCategoryPrefix + category});
     // Show the category name in the selection UI.
     base::trace_event::TraceLog::GetCategoryGroupEnabled(
         categories_.back().full_name.c_str());
@@ -68,6 +69,7 @@ void ArcTracingBridge::OnCategoriesReady(
 
 void ArcTracingBridge::StartTracing(
     const base::trace_event::TraceConfig& trace_config,
+    base::ScopedFD write_fd,
     const StartTracingCallback& callback) {
   DCHECK_CURRENTLY_ON(content::BrowserThread::UI);
 
@@ -87,7 +89,9 @@ void ArcTracingBridge::StartTracing(
       selected_categories.push_back(category.name);
   }
 
-  tracing_instance->StartTracing(selected_categories, callback);
+  tracing_instance->StartTracing(selected_categories,
+                                 mojo::WrapPlatformFile(write_fd.release()),
+                                 callback);
 }
 
 void ArcTracingBridge::StopTracing(const StopTracingCallback& callback) {

chrome/browser/chromeos/arc/tracing/arc_tracing_bridge.h

@@ -8,6 +8,7 @@
 #include <string>
 #include <vector>
 
+#include "base/files/scoped_file.h"
 #include "base/macros.h"
 #include "base/memory/weak_ptr.h"
 #include "base/trace_event/trace_event.h"
@@ -34,6 +35,7 @@ class ArcTracingBridge
 
   // content::ArcTracingAgent::Delegate overrides:
   void StartTracing(const base::trace_event::TraceConfig& trace_config,
+                    base::ScopedFD write_fd,
                     const StartTracingCallback& callback) override;
   void StopTracing(const StopTracingCallback& callback) override;
 

components/arc/common/tracing.mojom

@@ -2,7 +2,7 @@
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
-// Next MinVersion: 1
+// Next MinVersion: 2
 
 module arc.mojom;
 
@@ -10,8 +10,11 @@ interface TracingInstance {
   // Queries available tracing categories in the container.
   QueryAvailableCategories@0() => (array<string> categories);
 
-  // Starts tracing in the container with the given categories.
-  StartTracing@1(array<string> categories) => (bool success);
+  // Starts tracing in the container with the given categories. A handle is
+  // passed to the client for sending trace events back to the host. The client
+  // should send trace event as a JSON object in each write.
+  StartTracing@1(array<string> categories,
+                 [MinVersion=1] handle? socket) => (bool success);
 
   // Stops tracing in the container.
   StopTracing@2() => (bool success);

content/browser/BUILD.gn

@@ -1415,8 +1415,6 @@ source_set("browser") {
     "streams/stream_write_observer.h",
     "theme_helper_mac.h",
     "theme_helper_mac.mm",
-    "tracing/arc_tracing_agent.cc",
-    "tracing/arc_tracing_agent.h",
     "tracing/background_memory_tracing_observer.cc",
     "tracing/background_memory_tracing_observer.h",
     "tracing/background_tracing_config_impl.cc",
@@ -1546,6 +1544,12 @@ source_set("browser") {
       "tracing/power_tracing_agent.h",
     ]
   }
+  if (is_chromeos) {
+    sources += [
+      "tracing/arc_tracing_agent.cc",
+      "tracing/arc_tracing_agent.h",
+    ]
+  }
 
   if (enable_webrtc) {
     sources += [

content/browser/tracing/arc_tracing_agent.cc

@@ -4,24 +4,123 @@
 
 #include "content/browser/tracing/arc_tracing_agent.h"
 
+#include <memory>
 #include <string>
+#include <utility>
+#include <vector>
 
 #include "base/bind.h"
+#include "base/bind_helpers.h"
+#include "base/files/file.h"
+#include "base/files/file_descriptor_watcher_posix.h"
 #include "base/logging.h"
+#include "base/memory/ptr_util.h"
 #include "base/memory/singleton.h"
-#include "base/threading/thread_checker.h"
+#include "base/memory/weak_ptr.h"
+#include "base/posix/unix_domain_socket_linux.h"
+#include "base/threading/sequenced_task_runner_handle.h"
 #include "base/threading/thread_task_runner_handle.h"
+#include "base/time/time.h"
+#include "cc/base/ring_buffer.h"
+#include "content/public/browser/browser_thread.h"
 
 namespace content {
 
 namespace {
 
+// The maximum size used to store one trace event. The ad hoc trace format for
+// atrace is 1024 bytes. Here we add additional size as we're using JSON and
+// have additional data fields.
+constexpr size_t kArcTraceMessageLength = 1024 + 512;
+
 constexpr char kArcTracingAgentName[] = "arc";
 constexpr char kArcTraceLabel[] = "ArcTraceEvents";
 
-void OnStopTracing(bool success) {
-  DLOG_IF(WARNING, !success) << "Failed to stop ARC tracing.";
-}
+// Number of events for the ring buffer.
+constexpr size_t kTraceEventBufferSize = 64000;
+
+// A helper class for reading trace data from the client side. We separate this
+// from |ArcTracingAgentImpl| to isolate the logic that runs on browser's IO
+// thread. All the functions in this class except for constructor, destructor,
+// and |GetWeakPtr| are expected to be run on browser's IO thread.
+class ArcTracingReader {
+ public:
+  using StopTracingCallback =
+      base::Callback<void(const scoped_refptr<base::RefCountedString>&)>;
+
+  ArcTracingReader() : weak_ptr_factory_(this) {}
+
+  void StartTracing(base::ScopedFD read_fd) {
+    DCHECK_CURRENTLY_ON(BrowserThread::IO);
+    read_fd_ = std::move(read_fd);
+    // We don't use the weak pointer returned by |GetWeakPtr| to avoid using it
+    // on different task runner. Instead, we use |base::Unretained| here as
+    // |fd_watcher_| is always destroyed before |this| is destroyed.
+    fd_watcher_ = base::FileDescriptorWatcher::WatchReadable(
+        read_fd_.get(), base::Bind(&ArcTracingReader::OnTraceDataAvailable,
+                                   base::Unretained(this)));
+  }
+
+  void OnTraceDataAvailable() {
+    DCHECK_CURRENTLY_ON(BrowserThread::IO);
+
+    char buf[kArcTraceMessageLength];
+    std::vector<base::ScopedFD> unused_fds;
+    ssize_t n = base::UnixDomainSocket::RecvMsg(
+        read_fd_.get(), buf, kArcTraceMessageLength, &unused_fds);
+    // When EOF, return and do nothing. The clean up is done in StopTracing.
+    if (n == 0)
+      return;
+
+    if (n < 0) {
+      DPLOG(WARNING) << "Unexpected error while reading trace from client.";
+      // Do nothing here as StopTracing will do the clean up and the existing
+      // trace logs will be returned.
+      return;
+    }
+
+    if (n > static_cast<ssize_t>(kArcTraceMessageLength)) {
+      DLOG(WARNING) << "Unexpected data size when reading trace from client.";
+      return;
+    }
+    ring_buffer_.SaveToBuffer(std::string(buf, n));
+  }
+
+  void StopTracing(const StopTracingCallback& callback) {
+    DCHECK_CURRENTLY_ON(BrowserThread::IO);
+    fd_watcher_.reset();
+    read_fd_.reset();
+
+    bool append_comma = false;
+    std::string data;
+    for (auto it = ring_buffer_.Begin(); it; ++it) {
+      if (append_comma)
+        data.append(",");
+      else
+        append_comma = true;
+      data.append(**it);
+    }
+    ring_buffer_.Clear();
+
+    BrowserThread::PostTask(
+        BrowserThread::IO, FROM_HERE,
+        base::Bind(callback, base::RefCountedString::TakeString(&data)));
+  }
+
+  base::WeakPtr<ArcTracingReader> GetWeakPtr() {
+    return weak_ptr_factory_.GetWeakPtr();
+  }
+
+ private:
+  base::ScopedFD read_fd_;
+  std::unique_ptr<base::FileDescriptorWatcher::Controller> fd_watcher_;
+  cc::RingBuffer<std::string, kTraceEventBufferSize> ring_buffer_;
+  // NOTE: Weak pointers must be invalidated before all other member variables
+  // so it must be the last member.
+  base::WeakPtrFactory<ArcTracingReader> weak_ptr_factory_;
+
+  DISALLOW_COPY_AND_ASSIGN(ArcTracingReader);
+};
 
 class ArcTracingAgentImpl : public ArcTracingAgent {
  public:
@@ -32,10 +131,16 @@ class ArcTracingAgentImpl : public ArcTracingAgent {
 
   void StartAgentTracing(const base::trace_event::TraceConfig& trace_config,
                          const StartAgentTracingCallback& callback) override {
-    DCHECK(thread_checker_.CalledOnValidThread());
+    DCHECK_CURRENTLY_ON(BrowserThread::UI);
+
     // delegate_ may be nullptr if ARC is not enabled on the system. In such
     // case, simply do nothing.
-    if (!delegate_) {
+    bool success = (delegate_ != nullptr);
+
+    base::ScopedFD write_fd, read_fd;
+    success = success && CreateSocketPair(&read_fd, &write_fd);
+
+    if (!success) {
       // Use PostTask as the convention of TracingAgent. The caller expects
       // callback to be called after this function returns.
       base::ThreadTaskRunnerHandle::Get()->PostTask(
@@ -43,27 +148,33 @@ class ArcTracingAgentImpl : public ArcTracingAgent {
       return;
     }
 
-    delegate_->StartTracing(trace_config,
+    BrowserThread::PostTask(
+        BrowserThread::IO, FROM_HERE,
+        base::Bind(&ArcTracingReader::StartTracing, reader_.GetWeakPtr(),
+                   base::Passed(&read_fd)));
+
+    delegate_->StartTracing(trace_config, std::move(write_fd),
                             base::Bind(callback, GetTracingAgentName()));
   }
 
   void StopAgentTracing(const StopAgentTracingCallback& callback) override {
-    DCHECK(thread_checker_.CalledOnValidThread());
-    if (delegate_)
-      delegate_->StopTracing(base::Bind(OnStopTracing));
-
-    // Trace data is collect via systrace (debugd) in dev-mode. Simply
-    // return empty data here.
-    std::string no_data;
-    base::ThreadTaskRunnerHandle::Get()->PostTask(
-        FROM_HERE,
-        base::Bind(callback, GetTracingAgentName(), GetTraceEventLabel(),
-                   base::RefCountedString::TakeString(&no_data)));
+    DCHECK_CURRENTLY_ON(BrowserThread::UI);
+
+    if (is_stopping_) {
+      DLOG(WARNING) << "Already working on stopping ArcTracingAgent.";
+      return;
+    }
+    is_stopping_ = true;
+    if (delegate_) {
+      delegate_->StopTracing(
+          base::Bind(&ArcTracingAgentImpl::OnArcTracingStopped,
+                     weak_ptr_factory_.GetWeakPtr(), callback));
+    }
   }
 
   // ArcTracingAgent overrides:
   void SetDelegate(Delegate* delegate) override {
-    DCHECK(thread_checker_.CalledOnValidThread());
+    DCHECK_CURRENTLY_ON(BrowserThread::UI);
     delegate_ = delegate;
   }
 
@@ -76,11 +187,48 @@ class ArcTracingAgentImpl : public ArcTracingAgent {
   // by the Singleton class.
   friend struct base::DefaultSingletonTraits<ArcTracingAgentImpl>;
 
-  ArcTracingAgentImpl() = default;
+  ArcTracingAgentImpl() : weak_ptr_factory_(this) {}
+
   ~ArcTracingAgentImpl() override = default;
 
+  void OnArcTracingStopped(const StopAgentTracingCallback& callback,
+                           bool success) {
+    DCHECK_CURRENTLY_ON(BrowserThread::UI);
+    if (!success) {
+      DLOG(WARNING) << "Failed to stop ARC tracing.";
+      callback.Run(GetTracingAgentName(), GetTraceEventLabel(),
+                   new base::RefCountedString());
+      is_stopping_ = false;
+      return;
+    }
+    BrowserThread::PostTask(
+        BrowserThread::IO, FROM_HERE,
+        base::Bind(&ArcTracingReader::StopTracing, reader_.GetWeakPtr(),
+                   base::Bind(&ArcTracingAgentImpl::OnTracingReaderStopped,
+                              weak_ptr_factory_.GetWeakPtr(), callback)));
+  }
+
+  void OnTracingReaderStopped(
+      const StopAgentTracingCallback& callback,
+      const scoped_refptr<base::RefCountedString>& data) {
+    DCHECK_CURRENTLY_ON(BrowserThread::UI);
+    callback.Run(GetTracingAgentName(), GetTraceEventLabel(), data);
+    is_stopping_ = false;
+  }
+
   Delegate* delegate_ = nullptr;  // Owned by ArcServiceLauncher.
-  base::ThreadChecker thread_checker_;
+  // We use |reader_.GetWeakPtr()| when binding callbacks with its functions.
+  // Notes that the weak pointer returned by it can only be deferenced or
+  // invalided in the same task runner to avoid racing condition. The
+  // destruction of |reader_| is also a source of invalidation. However, we're
+  // lucky as we're using |ArcTracingAgentImpl| as a singleton, the
+  // destruction is always performed after all MessageLoops are destroyed, and
+  // thus there are no race conditions in such situation.
+  ArcTracingReader reader_;
+  bool is_stopping_ = false;
+  // NOTE: Weak pointers must be invalidated before all other member variables
+  // so it must be the last member.
+  base::WeakPtrFactory<ArcTracingAgentImpl> weak_ptr_factory_;
 
   DISALLOW_COPY_AND_ASSIGN(ArcTracingAgentImpl);
 };

content/browser/tracing/arc_tracing_agent.h

@@ -6,6 +6,7 @@
 #define CONTENT_BROWSER_TRACING_ARC_TRACING_AGENT_H_
 
 #include "base/callback_forward.h"
+#include "base/files/scoped_file.h"
 #include "base/macros.h"
 #include "base/trace_event/trace_event.h"
 #include "base/trace_event/tracing_agent.h"
@@ -33,6 +34,7 @@ class CONTENT_EXPORT ArcTracingAgent : public base::trace_event::TracingAgent {
     // Starts tracing in ARC container.
     virtual void StartTracing(
         const base::trace_event::TraceConfig& trace_config,
+        base::ScopedFD write_fd,
         const StartTracingCallback& callback) = 0;
 
     // Stops tracing in ARC container.

content/browser/tracing/tracing_controller_impl.cc

@@ -598,10 +598,11 @@ void TracingControllerImpl::OnEndAgentTracingAcked(
       // The Windows kernel events are kept into a JSON format stored as string
       // and must not be escaped.
       trace_data_sink_->AddAgentTrace(events_label, events_str_ptr->data());
-    } else if (agent_name != kArcTracingAgentName) {
-      // ARC trace data is obtained via systrace. Ignore the empty data.
-      // Quote other trace data as JSON strings and merge them into
-      // |trace_data_sink_|.
+    } else if (agent_name == kArcTracingAgentName) {
+      // The ARC events are kept into a JSON format stored as string
+      // and must not be escaped.
+      trace_data_sink_->AddTraceChunk(events_str_ptr->data());
+    } else {
       trace_data_sink_->AddAgentTrace(
           events_label, base::GetQuotedJSONString(events_str_ptr->data()));
     }