base/debug/trace_event_android.cc

// Copyright (c) 2012 The Chromium Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.

#include "base/debug/trace_event_impl.h"

#include <fcntl.h>

#include "base/debug/trace_event.h"
#include "base/format_macros.h"
#include "base/logging.h"
#include "base/strings/stringprintf.h"
#include "base/synchronization/waitable_event.h"

namespace {

int g_atrace_fd = -1;
const char* kATraceMarkerFile = "/sys/kernel/debug/tracing/trace_marker";

void WriteEvent(
    char phase,
    const char* category_group,
    const char* name,
    unsigned long long id,
    const char** arg_names,
    const unsigned char* arg_types,
    const base::debug::TraceEvent::TraceValue* arg_values,
    const scoped_refptr<base::debug::ConvertableToTraceFormat>*
        convertable_values,
    unsigned char flags) {
  std::string out = base::StringPrintf("%c|%d|%s", phase, getpid(), name);
  if (flags & TRACE_EVENT_FLAG_HAS_ID)
    base::StringAppendF(&out, "-%" PRIx64, static_cast<uint64>(id));
  out += '|';

  for (int i = 0; i < base::debug::kTraceMaxNumArgs && arg_names[i]; ++i) {
    if (i)
      out += ';';
    out += arg_names[i];
    out += '=';
    std::string::size_type value_start = out.length();
    if (arg_types[i] == TRACE_VALUE_TYPE_CONVERTABLE) {
      convertable_values[i]->AppendAsTraceFormat(&out);
    } else {
      base::debug::TraceEvent::AppendValueAsJSON(
          arg_types[i], arg_values[i], &out);
    }
    // Remove the quotes which may confuse the atrace script.
    ReplaceSubstringsAfterOffset(&out, value_start, "\\\"", "'");
    ReplaceSubstringsAfterOffset(&out, value_start, "\"", "");
    // Replace chars used for separators with similar chars in the value.
    std::replace(out.begin() + value_start, out.end(), ';', ',');
    std::replace(out.begin() + value_start, out.end(), '|', '!');
  }

  out += '|';
  out += category_group;
  write(g_atrace_fd, out.c_str(), out.size());
}

void NoOpOutputCallback(base::WaitableEvent* complete_event,
                        const scoped_refptr<base::RefCountedString>&,
                        bool has_more_events) {
  if (!has_more_events)
    complete_event->Signal();
}

void EndChromeTracing(base::debug::TraceLog* trace_log,
                      base::WaitableEvent* complete_event) {
  trace_log->SetDisabled();
  // Delete the buffered trace events as they have been sent to atrace.
  trace_log->Flush(base::Bind(&NoOpOutputCallback, complete_event));
}

}  // namespace

namespace base {
namespace debug {

// These functions support Android systrace.py when 'webview' category is
// traced. With the new adb_profile_chrome, we may have two phases:
// - before WebView is ready for combined tracing, we can use adb_profile_chrome
//   to trace android categories other than 'webview' and chromium categories.
//   In this way we can avoid the conflict between StartATrace/StopATrace and
//   the intents.
// - TODO(wangxianzhu): after WebView is ready for combined tracing, remove
//   StartATrace, StopATrace and SendToATrace, and perhaps send Java traces
//   directly to atrace in trace_event_binding.cc.

void TraceLog::StartATrace() {
  if (g_atrace_fd != -1)
    return;

  g_atrace_fd = open(kATraceMarkerFile, O_WRONLY);
  if (g_atrace_fd == -1) {
    PLOG(WARNING) << "Couldn't open " << kATraceMarkerFile;
    return;
  }
  SetEnabled(CategoryFilter(CategoryFilter::kDefaultCategoryFilterString),
             TraceLog::RECORDING_MODE,
             TraceOptions(RECORD_CONTINUOUSLY));
}

void TraceLog::StopATrace() {
  if (g_atrace_fd == -1)
    return;

  close(g_atrace_fd);
  g_atrace_fd = -1;

  // TraceLog::Flush() requires the current thread to have a message loop, but
  // this thread called from Java may not have one, so flush in another thread.
  Thread end_chrome_tracing_thread("end_chrome_tracing");
  WaitableEvent complete_event(false, false);
  end_chrome_tracing_thread.Start();
  end_chrome_tracing_thread.message_loop()->PostTask(
      FROM_HERE, base::Bind(&EndChromeTracing, Unretained(this),
                            Unretained(&complete_event)));
  complete_event.Wait();
}

void TraceEvent::SendToATrace() {
  if (g_atrace_fd == -1)
    return;

  const char* category_group =
      TraceLog::GetCategoryGroupName(category_group_enabled_);

  switch (phase_) {
    case TRACE_EVENT_PHASE_BEGIN:
      WriteEvent('B', category_group, name_, id_,
                 arg_names_, arg_types_, arg_values_, convertable_values_,
                 flags_);
      break;

    case TRACE_EVENT_PHASE_COMPLETE:
      WriteEvent(duration_.ToInternalValue() == -1 ? 'B' : 'E',
                 category_group, name_, id_,
                 arg_names_, arg_types_, arg_values_, convertable_values_,
                 flags_);
      break;

    case TRACE_EVENT_PHASE_END:
      // Though a single 'E' is enough, here append pid, name and
      // category_group etc. So that unpaired events can be found easily.
      WriteEvent('E', category_group, name_, id_,
                 arg_names_, arg_types_, arg_values_, convertable_values_,
                 flags_);
      break;

    case TRACE_EVENT_PHASE_INSTANT:
      // Simulate an instance event with a pair of begin/end events.
      WriteEvent('B', category_group, name_, id_,
                 arg_names_, arg_types_, arg_values_, convertable_values_,
                 flags_);
      write(g_atrace_fd, "E", 1);
      break;

    case TRACE_EVENT_PHASE_COUNTER:
      for (int i = 0; i < kTraceMaxNumArgs && arg_names_[i]; ++i) {
        DCHECK(arg_types_[i] == TRACE_VALUE_TYPE_INT);
        std::string out = base::StringPrintf(
            "C|%d|%s-%s", getpid(), name_, arg_names_[i]);
        if (flags_ & TRACE_EVENT_FLAG_HAS_ID)
          StringAppendF(&out, "-%" PRIx64, static_cast<uint64>(id_));
        StringAppendF(&out, "|%d|%s",
                      static_cast<int>(arg_values_[i].as_int), category_group);
        write(g_atrace_fd, out.c_str(), out.size());
      }
      break;

    default:
      // Do nothing.
      break;
  }
}

void TraceLog::AddClockSyncMetadataEvent() {
  int atrace_fd = open(kATraceMarkerFile, O_WRONLY | O_APPEND);
  if (atrace_fd == -1) {
    PLOG(WARNING) << "Couldn't open " << kATraceMarkerFile;
    return;
  }

  // Android's kernel trace system has a trace_marker feature: this is a file on
  // debugfs that takes the written data and pushes it onto the trace
  // buffer. So, to establish clock sync, we write our monotonic clock into that
  // trace buffer.
  TimeTicks now = TimeTicks::NowFromSystemTraceTime();
  double now_in_seconds = now.ToInternalValue() / 1000000.0;
  std::string marker = StringPrintf(
      "trace_event_clock_sync: parent_ts=%f\n", now_in_seconds);
  if (write(atrace_fd, marker.c_str(), marker.size()) == -1)
    PLOG(WARNING) << "Couldn't write to " << kATraceMarkerFile;
  close(atrace_fd);
}

}  // namespace debug
}  // namespace base