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..36576888de6802d470eace928d108b669116cdcc 100644
--- a/content/browser/tracing/arc_tracing_agent.cc
+++ b/content/browser/tracing/arc_tracing_agent.cc
@@ -4,24 +4,165 @@
 
 #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/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/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 "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() : weak_ptr_factory_(this) {}
+
+  void StartTracing(int read_fd) {

[Luis Héctor Chávez, 2017/04/04 17:28:35]

As mentioned below, make this a ScopedFD.

[shunhsingou, 2017/04/05 03:41:50]

Done.

+    DCHECK_CURRENTLY_ON(BrowserThread::IO);
+    read_fd_.reset(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,
+                                   weak_ptr_factory_.GetWeakPtr()));
+  }
+
+  void OnTraceDataAvailable() {
+    DCHECK_CURRENTLY_ON(BrowserThread::IO);
+
+    char buf[kArcTraceMessageLength + 1];

[Luis Héctor Chávez, 2017/04/04 17:28:35]

nit: You don't need the +1 here.

[shunhsingou, 2017/04/05 03:42:45]

Done.

+    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) {
+      LOG(WARNING) << "Unexpected error while reading trace from client: "

[Luis Héctor Chávez, 2017/04/04 17:28:35]

nit: PLOG(WARNING) << "Unexpected error while reading trace from client.";

PLOG already prints out strerror(errno).

[shunhsingou, 2017/04/05 03:41:51]

Done.

+                   << strerror(errno);
+      // Do nothing here as StopTracing will do the clean up and the existing
+      // trace logs will be returned.
+      return;
+    }
+
+    if (n > (ssize_t)kArcTraceMessageLength) {

[Luis Héctor Chávez, 2017/04/04 17:28:35]

Avoid C-style casts. static_cast<ssize_t>(kArcTraceMessageLength)

[shunhsingou, 2017/04/05 03:41:51]

Done.

+      LOG(WARNING) << "Unexpected data size when reading trace from client.";
+      return;
+    }
+
+    char* data = new char[n + 1];

[Luis Héctor Chávez, 2017/04/04 17:28:34]

avoid doing this as much as possible. Instead do:

std::unique_ptr<char[]> data = base::MakeUnique<char[]>(n + 1);

[shunhsingou, 2017/04/05 03:41:51]

Done.

+    memcpy(data, 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
+    // 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);
+    if (value.get() == nullptr) {
+      LOG(WARNING) << "Get incorrect trace data from container: " << data;

[Luis Héctor Chávez, 2017/04/04 17:28:34]

I'd probably not log the data because it might be too large.

[shunhsingou, 2017/04/05 03:41:51]

Done.

+      return;
+    }
+
+    // Save data into trace buffer.
+    if (!chunk_)
+      chunk_ = trace_buffer_->GetChunk(&chunk_index_);
+    size_t event_index;
+    TraceEvent* event = chunk_->AddTraceEvent(&event_index);
+
+    event->Initialize(0, base::TimeTicks(), base::ThreadTicks(), 0, nullptr,
+                      data, 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_);
+    }
+  }
+
+  void StopTracing(const StopTracingCallback& callback) {
+    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();

[Luis Héctor Chávez, 2017/04/04 17:28:35]

Eek. What happens if the chunk is evicted because the size exceeds the buffer
size? (I'm guessing memory leaks).

[shunhsingou, 2017/04/05 03:41:51]

Right. It leaks here. I added a checking code when we get reused event.

+      }
+    }
+    callback.Run(base::RefCountedString::TakeString(&data));

[Luis Héctor Chávez, 2017/04/04 17:28:34]

Keep in mind that this will make OnTracingReaderStopped be run in the IO thread,
which is probably not what you want. Please post a task in the UI thread to run
the callback correctly. Alternatively, try to do:

base::RefCountedString StopTracing() {
  // ...
  return base::RefCountedString::TakeString(&data);
}

// ...

bool PostTaskAndReplyWithResult(
  // the IO thread runner,
  FROM_HERE,
  base::Bind(&ArcTracingReader::StopTracing, reader_->GetWeakPtr()),
  base::Bind(&ArcTracingAgentImpl::OnTracingReaderStopped,
             weak_ptr_factory_.GetWeakPtr(), callback)));

[shunhsingou, 2017/04/05 03:41:50]

Done.

+  }
+
+  base::WeakPtr<ArcTracingReader> GetWeakPtr() {
+    return weak_ptr_factory_.GetWeakPtr();
+  }
+
+ 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;
+
+  // NOTE: Weak pointers must be invalidated before all other member variables
+  // so it must be the last member.
+  base::WeakPtrFactory<ArcTracingReader> weak_ptr_factory_;
+};
 
 class ArcTracingAgentImpl : public ArcTracingAgent {
  public:
@@ -32,10 +173,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;

[Luis Héctor Chávez, 2017/04/04 17:28:34]

Creating a socket pair when ARC is not enabled seems wasteful. Please keep the
old semantics:

if (!delegate_) {
  base::Thread...
  return;
}

base::ScopedFD write_fd, read_fd;
if (!CreateSocketPair(&read_fd, &write_fd)) {
  base::Thread...
  return;
}

[shunhsingou, 2017/04/05 03:41:50]

It should be short-circuited. Fixed the statement here.

+
+    base::ScopedFD write_fd, read_fd;
+    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 +190,33 @@ class ArcTracingAgentImpl : public ArcTracingAgent {
       return;
     }
 
-    delegate_->StartTracing(trace_config,
+    BrowserThread::PostTask(
+        BrowserThread::IO, FROM_HERE,
+        base::Bind(&ArcTracingReader::StartTracing, reader_->GetWeakPtr(),
+                   read_fd.release()));

[Luis Héctor Chávez, 2017/04/04 17:28:34]

you can do base::Passed(std::move(read_fd)) instead of read_fd.release(). Thay
way StartTracing can receive a base::ScopedFD instead of a raw int.

[shunhsingou, 2017/04/05 03:41:51]

Done.

+
+    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 +229,41 @@ 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) {

[Luis Héctor Chávez, 2017/04/04 17:28:35]

DCHECK_CURRENTLY_ON(BrowserThread::UI);?

[shunhsingou, 2017/04/05 03:41:50]

Done.

+    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::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) {

[Luis Héctor Chávez, 2017/04/04 17:28:34]

DCHECK_CURRENTLY_ON(BrowserThread::UI);?

[shunhsingou, 2017/04/05 03:41:50]

Done.

+    callback.Run(GetTracingAgentName(), GetTraceEventLabel(), data);
+    is_stopping = false;
+  }
+
   Delegate* delegate_ = nullptr;  // Owned by ArcServiceLauncher.
-  base::ThreadChecker thread_checker_;
+  std::unique_ptr<ArcTracingReader> reader_ =

[Luis Héctor Chávez, 2017/04/04 17:28:34]

nit: move the initialization to the constructor.

[shunhsingou, 2017/04/05 03:41:50]

Done.

+      base::MakeUnique<ArcTracingReader>();
+  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);
 };