arc: enable Android tracing in verified-boot mode

content/browser/tracing/arc_tracing_agent.cc

Index: content/browser/tracing/arc_tracing_agent.cc
diff --git a/content/browser/tracing/arc_tracing_agent.cc b/content/browser/tracing/arc_tracing_agent.cc
index d71cd647ae870308c2d5c68e3f600c2345115814..9ccadc4c9d822844bb450e2bc7946d9505568d1c 100644
--- a/content/browser/tracing/arc_tracing_agent.cc
+++ b/content/browser/tracing/arc_tracing_agent.cc
@@ -4,24 +4,163 @@
 
 #include "content/browser/tracing/arc_tracing_agent.h"
 
+#include <string.h>
+#include <sys/socket.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/json/json_reader.h"
 #include "base/logging.h"
+#include "base/memory/ptr_util.h"
 #include "base/memory/singleton.h"
-#include "base/threading/thread_checker.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 "base/trace_event/trace_buffer.h"
+#include "content/public/browser/browser_thread.h"
+
+using base::trace_event::TraceEvent;
+using base::trace_event::TraceBuffer;
+using base::trace_event::TraceBufferChunk;
 
 namespace content {
 
 namespace {
 
+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 chunks for the ring buffer.
+constexpr size_t kTraceEventChunks =
+    64000 / TraceBufferChunk::kTraceBufferChunkSize;
+
+class ArcTracingReader {
+ public:
+  using StopTracingCallback =
+      base::Callback<void(const scoped_refptr<base::RefCountedString>&)>;
+
+  ArcTracingReader() = default;
+
+  void StartTracing(base::ScopedFD read_fd) {
+    DCHECK_CURRENTLY_ON(BrowserThread::IO);
+    read_fd_ = std::move(read_fd);
+    trace_buffer_.reset(
+        TraceBuffer::CreateTraceBufferRingBuffer(kTraceEventChunks));
+    chunk_.reset();
+    chunk_index_ = 0;
+    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) {
+      PLOG(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)) {
+      LOG(WARNING) << "Unexpected data size when reading trace from client.";
+      return;
+    }
+
+    std::unique_ptr<char[]> data = base::MakeUnique<char[]>(n + 1);
+    memcpy(data.get(), buf, n);
+    data[n] = 0;
+
+    // Here we only validate the data, which should be a JSON string. But we
+    // don't really parse them into the fields of |TraceEvent|. It's because
+    // |TraceEvent| is designed for Chrome trace. There are many restricion in

[Luis Héctor Chávez, 2017/04/06 00:59:08]

nit: s/restricion/restrictions/

[Earl Ou, 2017/04/06 04:49:20]

Done.

+    // its implementation, e.g., no pid and tid together, and no creation of
+    // TimeTicks with existing long value. The flags used for |TraceEvent| is
+    // also not suitable for our use case here.
+    //
+    // To avoid the issue, we put entire JSON string in the |name| field
+    // instead, so that we can still use |TraceBuffer| and |TraceBufferChunk|
+    // for data storage.
+    std::unique_ptr<base::Value> value = base::JSONReader::Read(data.get());
+    if (value.get() == nullptr) {
+      LOG(WARNING) << "Get incorrect trace data from container.";
+      return;
+    }
+
+    // Save data into trace buffer.
+    if (!chunk_)
+      chunk_ = trace_buffer_->GetChunk(&chunk_index_);
+    size_t event_index;
+    TraceEvent* event = chunk_->AddTraceEvent(&event_index);
+
+    // If this is a reused event, free the data we saved previously before
+    // calling Initialize() again.
+    if (event->name() != nullptr)
+      delete[] event->name();
+
+    event->Initialize(0, base::TimeTicks(), base::ThreadTicks(), 0, nullptr,
+                      data.release(), nullptr, 0, 0, 0, nullptr, nullptr,
+                      nullptr, nullptr, 0);
+
+    if (chunk_->IsFull()) {
+      trace_buffer_->ReturnChunk(chunk_index_, std::move(chunk_));
+      chunk_ = trace_buffer_->GetChunk(&chunk_index_);
+    }
+  }
+
+  scoped_refptr<base::RefCountedString> StopTracing() {
+    DCHECK_CURRENTLY_ON(BrowserThread::IO);
+    // Stop fd_watcher_.
+    fd_watcher_.reset();
+    read_fd_.reset();
+
+    if (chunk_)
+      trace_buffer_->ReturnChunk(chunk_index_, std::move(chunk_));
+
+    bool append_comma = false;
+    std::string data;
+    while (const TraceBufferChunk* chunk = trace_buffer_->NextChunk()) {
+      for (size_t i = 0; i < chunk->size(); ++i) {
+        const TraceEvent* event = chunk->GetEventAt(i);
+        if (append_comma)
+          data.append(",");
+        // See comment in |OnTraceDataAvailable|. We put the whole valid JSON
+        // object in |name|.
+        data.append(event->name());
+        append_comma = true;
+        delete[] event->name();
+      }
+    }
+    return base::RefCountedString::TakeString(&data);
+  }
+
+ private:
+  base::ScopedFD read_fd_;
+  std::unique_ptr<base::FileDescriptorWatcher::Controller> fd_watcher_;
+  std::unique_ptr<TraceBuffer> trace_buffer_;
+  std::unique_ptr<TraceBufferChunk> chunk_;
+  size_t chunk_index_ = 0;
+
+  DISALLOW_COPY_AND_ASSIGN(ArcTracingReader);
+};
 
 class ArcTracingAgentImpl : public ArcTracingAgent {
  public:
@@ -32,10 +171,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 +188,33 @@ class ArcTracingAgentImpl : public ArcTracingAgent {
       return;
     }
 
-    delegate_->StartTracing(trace_config,
+    BrowserThread::PostTask(BrowserThread::IO, FROM_HERE,
+                            base::Bind(&ArcTracingReader::StartTracing,
+                                       base::Unretained(reader_.get()),
+                                       base::Passed(std::move(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,
+                     base::Unretained(this), callback));
+    }
   }
 
   // ArcTracingAgent overrides:
   void SetDelegate(Delegate* delegate) override {
-    DCHECK(thread_checker_.CalledOnValidThread());
+    DCHECK_CURRENTLY_ON(BrowserThread::UI);
     delegate_ = delegate;
   }
 
@@ -76,11 +227,40 @@ class ArcTracingAgentImpl : public ArcTracingAgent {
   // by the Singleton class.
   friend struct base::DefaultSingletonTraits<ArcTracingAgentImpl>;
 
-  ArcTracingAgentImpl() = default;
+  ArcTracingAgentImpl() : reader_(base::MakeUnique<ArcTracingReader>()) {}
+
   ~ArcTracingAgentImpl() override = default;
 
+  void OnArcTracingStopped(const StopAgentTracingCallback& callback,
+                           bool success) {
+    DCHECK_CURRENTLY_ON(BrowserThread::UI);
+    if (!success) {
+      DLOG(WARNING) << "Failed to stop ARC tracing.";
+      std::string no_data;
+      callback.Run(GetTracingAgentName(), GetTraceEventLabel(),
+                   base::RefCountedString::TakeString(&no_data));
+      is_stopping = false;
+      return;
+    }
+    BrowserThread::PostTaskAndReplyWithResult(
+        BrowserThread::IO, FROM_HERE,
+        base::Bind(&ArcTracingReader::StopTracing,
+                   base::Unretained(reader_.get())),
+        base::Bind(&ArcTracingAgentImpl::OnTracingReaderStopped,
+                   base::Unretained(this), callback));

[Luis Héctor Chávez, 2017/04/06 00:59:08]

IIUC there's nothing that guarantees that |this| will still be alive by the time
this is called. I *think* you still need to have the weak_ptr_factory_.

I'm also a bit unsure about L248. I'll take a look tomorrow again, but please
make sure you read the docs about WeakPtrFactory to see if it's legal to call
reader_.GetWeakPtr() in the UI thread and check it in the IO thread.

[Earl Ou, 2017/04/06 04:49:20]

Hmm. True. weak_ptr_factory_ is required as |this| might be invalid.

The problem is that we can't bind weak_ptr with function with return value. So I
change this back to PostTask instead of PostTaskAndReplyWithResult now.

For the thread issue, as the weak_ptr doc says:
"Weak pointers may be passed safely between threads, but must always be
dereferenced and invalidated on the same SequencedTaskRunner otherwise
checking the pointer would be racey."

If what I understand is correct, all the usage of weak_ptr here is by
BrowserThread::IO, so it should be safe to do this.

[Luis Héctor Chávez, 2017/04/07 16:17:46]

The destructor of |reader_| is another source of weak pointer invalidation, and
that one is definitely not run in the IO thread. Having said that, your class is
a Singleton, and its destructor will be run after all the messageloops are
destroyed (see base/Singleton.h and base/at_exit.h), there is no way that any
live |reader_| (weak) references are live after the IO thread is gone. So yes,
this should be safe, but might not be if we ever un-Singleton this class.

Please add a comment about this here :D

[Earl Ou, 2017/04/08 14:48:17]

Done adding the comments above the declaration of |reader_|.

+  }
+
+  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_;
+  std::unique_ptr<ArcTracingReader> reader_;
+  bool is_stopping = false;

[Luis Héctor Chávez, 2017/04/06 00:59:08]

nit: |is_stopping_|

[Earl Ou, 2017/04/06 04:49:20]

Done.

 
   DISALLOW_COPY_AND_ASSIGN(ArcTracingAgentImpl);
 };