Skip to content

Commit

Permalink
Independently enable recording and event callback
Browse files Browse the repository at this point in the history 
Previously we count TraceLog::SetEnabled() and SetDisabled() to allow
nested calls from about:tracing and Timeline panel of the DevTools.
Actually DevTools only needs the event callbacks, so we can allow the
two features (recording for about:tracing, event callback for DevTools)
to be independently enabled.

Also don't count TraceLog::SetEnabled() and SetDisabled() to ease
trace-startup and simplify the API semantics.

BUG=none
TEST=TraceEventCallbackTest.TraceEventCallbackAndRecording*, TraceEventTestFixture.*
R=caseq@chromium.org, nduca@chromium.org, pfeldman@chromium.org, tony@chromium.org
TBR=sky (for trivial call site change in content/browser/browser_shutdown_profile_dumper.cc)

Review URL: https://codereview.chromium.org/66193005

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@236078 0039d316-1c4b-4281-b951-d872f2087c98
  • Loading branch information
wangxianzhu@chromium.org committed Nov 20, 2013
1 parent 71aec4b commit dd37ea1
Show file tree
Hide file tree
Showing 8 changed files with 325 additions and 116 deletions.
11 changes: 9 additions & 2 deletions base/debug/trace_event.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -807,6 +807,8 @@

// Set the duration field of a COMPLETE trace event.
// void TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(
// const unsigned char* category_group_enabled,
// const char* name,
// base::debug::TraceEventHandle id)
#define TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION \
base::debug::TraceLog::GetInstance()->UpdateTraceEventDuration
Expand Down Expand Up @@ -888,7 +890,7 @@ TRACE_EVENT_API_CLASS_EXPORT extern \
name, trace_event_internal::kNoEventId, \
TRACE_EVENT_FLAG_NONE, ##__VA_ARGS__); \
INTERNAL_TRACE_EVENT_UID(tracer).Initialize( \
INTERNAL_TRACE_EVENT_UID(category_group_enabled), h); \
INTERNAL_TRACE_EVENT_UID(category_group_enabled), name, h); \
}

// Implementation detail: internal macro to create static category and add
Expand Down Expand Up @@ -1378,12 +1380,15 @@ class TRACE_EVENT_API_CLASS_EXPORT ScopedTracer {

~ScopedTracer() {
if (p_data_ && *data_.category_group_enabled)
TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(data_.event_handle);
TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(
data_.category_group_enabled, data_.name, data_.event_handle);
}

void Initialize(const unsigned char* category_group_enabled,
const char* name,
base::debug::TraceEventHandle event_handle) {
data_.category_group_enabled = category_group_enabled;
data_.name = name;
data_.event_handle = event_handle;
p_data_ = &data_;
}
Expand All @@ -1396,6 +1401,7 @@ class TRACE_EVENT_API_CLASS_EXPORT ScopedTracer {
// uninitialized accesses.
struct Data {
const unsigned char* category_group_enabled;
const char* name;
base::debug::TraceEventHandle event_handle;
};
Data* p_data_;
Expand All @@ -1410,6 +1416,7 @@ class TRACE_EVENT_API_CLASS_EXPORT ScopedTraceBinaryEfficient {

private:
const unsigned char* category_group_enabled_;
const char* name_;
base::debug::TraceEventHandle event_handle_;
};

Expand Down
144 changes: 88 additions & 56 deletions base/debug/trace_event_impl.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1149,7 +1149,7 @@ TraceLog::Options TraceLog::TraceOptionsFromString(const std::string& options) {
}

TraceLog::TraceLog()
: enable_count_(0),
: enabled_(false),
num_traces_recorded_(0),
buffer_is_full_(0),
event_callback_(0),
Expand All @@ -1161,6 +1161,8 @@ TraceLog::TraceLog()
trace_options_(RECORD_UNTIL_FULL),
sampling_thread_handle_(0),
category_filter_(CategoryFilter::kDefaultCategoryFilterString),
event_callback_category_filter_(
CategoryFilter::kDefaultCategoryFilterString),
thread_shared_chunk_index_(0),
generation_(0) {
// Trace is enabled or disabled on one thread while other threads are
Expand Down Expand Up @@ -1227,10 +1229,14 @@ const char* TraceLog::GetCategoryGroupName(
}

void TraceLog::UpdateCategoryGroupEnabledFlag(int category_index) {
g_category_group_enabled[category_index] =
enable_count_ &&
category_filter_.IsCategoryGroupEnabled(
g_category_groups[category_index]);
unsigned char enabled_flag = 0;
const char* category_group = g_category_groups[category_index];
if (enabled_ && category_filter_.IsCategoryGroupEnabled(category_group))
enabled_flag |= ENABLED_FOR_RECORDING;
if (event_callback_ &&
event_callback_category_filter_.IsCategoryGroupEnabled(category_group))
enabled_flag |= ENABLED_FOR_EVENT_CALLBACK;
g_category_group_enabled[category_index] = enabled_flag;
}

void TraceLog::UpdateCategoryGroupEnabledFlags() {
Expand Down Expand Up @@ -1299,7 +1305,7 @@ void TraceLog::SetEnabled(const CategoryFilter& category_filter,

Options old_options = trace_options();

if (enable_count_++ > 0) {
if (enabled_) {
if (options != old_options) {
DLOG(ERROR) << "Attemting to re-enable tracing with a different "
<< "set of options.";
Expand All @@ -1310,19 +1316,21 @@ void TraceLog::SetEnabled(const CategoryFilter& category_filter,
return;
}

if (dispatching_to_observer_list_) {
DLOG(ERROR) <<
"Cannot manipulate TraceLog::Enabled state from an observer.";
return;
}

enabled_ = true;

if (options != old_options) {
subtle::NoBarrier_Store(&trace_options_, options);
logged_events_.reset(CreateTraceBuffer());
NextGeneration();
subtle::NoBarrier_Store(&buffer_is_full_, 0);
}

if (dispatching_to_observer_list_) {
DLOG(ERROR) <<
"Cannot manipulate TraceLog::Enabled state from an observer.";
return;
}

num_traces_recorded_++;

category_filter_ = CategoryFilter(category_filter);
Expand Down Expand Up @@ -1361,19 +1369,16 @@ void TraceLog::SetEnabled(const CategoryFilter& category_filter,
}
}

const CategoryFilter& TraceLog::GetCurrentCategoryFilter() {
CategoryFilter TraceLog::GetCurrentCategoryFilter() {
AutoLock lock(lock_);
DCHECK(enable_count_ > 0);
return category_filter_;
}

void TraceLog::SetDisabled() {
std::vector<EnabledStateObserver*> observer_list;
{
AutoLock lock(lock_);
DCHECK(enable_count_ > 0);

if (--enable_count_ != 0)
if (!enabled_)
return;

if (dispatching_to_observer_list_) {
Expand All @@ -1382,6 +1387,8 @@ void TraceLog::SetDisabled() {
return;
}

enabled_ = false;

if (sampling_thread_.get()) {
// Stop the sampling thread.
sampling_thread_->Stop();
Expand Down Expand Up @@ -1415,7 +1422,7 @@ void TraceLog::SetDisabled() {

int TraceLog::GetNumTracesRecorded() {
AutoLock lock(lock_);
if (enable_count_ == 0)
if (!enabled_)
return -1;
return num_traces_recorded_;
}
Expand Down Expand Up @@ -1499,11 +1506,21 @@ void TraceLog::CheckIfBufferIsFullWhileLocked(NotificationHelper* notifier) {
}
}

void TraceLog::SetEventCallback(EventCallback cb) {
void TraceLog::SetEventCallbackEnabled(const CategoryFilter& category_filter,
EventCallback cb) {
AutoLock lock(lock_);
subtle::NoBarrier_Store(&event_callback_,
reinterpret_cast<subtle::AtomicWord>(cb));
event_callback_category_filter_ = category_filter;
UpdateCategoryGroupEnabledFlags();
};

void TraceLog::SetEventCallbackDisabled() {
AutoLock lock(lock_);
subtle::NoBarrier_Store(&event_callback_, 0);
UpdateCategoryGroupEnabledFlags();
}

// Flush() works as the following:
// 1. Flush() is called in threadA whose message loop is saved in
// flush_message_loop_proxy_;
Expand Down Expand Up @@ -1784,7 +1801,8 @@ TraceEventHandle TraceLog::AddTraceEventWithThreadIdAndTimestamp(
}

TraceEvent* trace_event = NULL;
if (!subtle::NoBarrier_Load(&buffer_is_full_)) {
if ((*category_group_enabled & ENABLED_FOR_RECORDING) &&
!subtle::NoBarrier_Load(&buffer_is_full_)) {
if (thread_local_event_buffer) {
lock.EnsureReleased();
trace_event = thread_local_event_buffer->AddTraceEvent(&notifier,
Expand Down Expand Up @@ -1821,17 +1839,17 @@ TraceEventHandle TraceLog::AddTraceEventWithThreadIdAndTimestamp(
}

lock.EnsureReleased();
EventCallback event_callback = reinterpret_cast<EventCallback>(
subtle::NoBarrier_Load(&event_callback_));
if (event_callback) {
// TODO(wangxianzhu): Should send TRACE_EVENT_PHASE_COMPLETE directly to
// clients if it is beneficial and feasible.
event_callback(now,
phase == TRACE_EVENT_PHASE_COMPLETE ?
TRACE_EVENT_PHASE_BEGIN : phase,
category_group_enabled, name, id,
num_args, arg_names, arg_types, arg_values,
flags);
if (*category_group_enabled & ENABLED_FOR_EVENT_CALLBACK) {
EventCallback event_callback = reinterpret_cast<EventCallback>(
subtle::NoBarrier_Load(&event_callback_));
if (event_callback) {
event_callback(now,
phase == TRACE_EVENT_PHASE_COMPLETE ?
TRACE_EVENT_PHASE_BEGIN : phase,
category_group_enabled, name, id,
num_args, arg_names, arg_types, arg_values,
flags);
}
}

if (thread_local_event_buffer)
Expand Down Expand Up @@ -1911,38 +1929,49 @@ void TraceLog::AddTraceEventEtw(char phase,
TRACE_EVENT_FLAG_COPY, "id", id, "extra", extra);
}

void TraceLog::UpdateTraceEventDuration(TraceEventHandle handle) {
void TraceLog::UpdateTraceEventDuration(
const unsigned char* category_group_enabled,
const char* name,
TraceEventHandle handle) {
OptionalAutoLock lock(lock_);

TimeTicks now = OffsetNow();
TraceEvent* trace_event = GetEventByHandleInternal(handle, &lock);
if (trace_event) {
DCHECK(trace_event->phase() == TRACE_EVENT_PHASE_COMPLETE);
trace_event->UpdateDuration(now);
TraceEvent* trace_event = NULL;
// TODO(wangxianzhu): Remove the !category_group_enabled condition after
// all clients migrate to the new UpdateTraceEventDuration API.
if (!category_group_enabled ||
(*category_group_enabled & ENABLED_FOR_RECORDING)) {
trace_event = GetEventByHandleInternal(handle, &lock);
if (trace_event) {
DCHECK(trace_event->phase() == TRACE_EVENT_PHASE_COMPLETE);
trace_event->UpdateDuration(now);
#if defined(OS_ANDROID)
trace_event->SendToATrace();
trace_event->SendToATrace();
#endif
}

if (trace_options() & ECHO_TO_CONSOLE) {
lock.EnsureAcquired();
OutputEventToConsoleWhileLocked(TRACE_EVENT_PHASE_END, now, trace_event);
}
}

if (trace_options() & ECHO_TO_CONSOLE) {
lock.EnsureAcquired();
OutputEventToConsoleWhileLocked(TRACE_EVENT_PHASE_END, now, trace_event);
// TODO(wangxianzhu): Remove this block after all clients migrate to the
// new UpdateTraceEventDuration API.
if (!category_group_enabled || !name) {
if (!trace_event)
return;
category_group_enabled = trace_event->category_group_enabled();
name = trace_event->name();
}

EventCallback event_callback = reinterpret_cast<EventCallback>(
subtle::NoBarrier_Load(&event_callback_));
if (event_callback && trace_event) {
// The copy is needed when trace_event is from the main buffer in which case
// the lock has been locked.
TraceEvent event_copy;
event_copy.CopyFrom(*trace_event);
lock.EnsureReleased();
// TODO(wangxianzhu): Should send TRACE_EVENT_PHASE_COMPLETE directly to
// clients if it is beneficial and feasible.
event_callback(now, TRACE_EVENT_PHASE_END,
event_copy.category_group_enabled(),
event_copy.name(), event_copy.id(),
0, NULL, NULL, NULL, event_copy.flags());
lock.EnsureReleased();
if (*category_group_enabled & ENABLED_FOR_EVENT_CALLBACK) {
EventCallback event_callback = reinterpret_cast<EventCallback>(
subtle::NoBarrier_Load(&event_callback_));
event_callback(now, TRACE_EVENT_PHASE_END, category_group_enabled, name,
trace_event_internal::kNoEventId, 0, NULL, NULL, NULL,
TRACE_EVENT_FLAG_NONE);
}
}

Expand Down Expand Up @@ -2286,6 +2315,7 @@ ScopedTraceBinaryEfficient::ScopedTraceBinaryEfficient(
static TRACE_EVENT_API_ATOMIC_WORD atomic = 0;
INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO_CUSTOM_VARIABLES(
category_group, atomic, category_group_enabled_);
name_ = name;
if (*category_group_enabled_) {
event_handle_ =
TRACE_EVENT_API_ADD_TRACE_EVENT_WITH_THREAD_ID_AND_TIMESTAMP(
Expand All @@ -2298,8 +2328,10 @@ ScopedTraceBinaryEfficient::ScopedTraceBinaryEfficient(
}

ScopedTraceBinaryEfficient::~ScopedTraceBinaryEfficient() {
if (*category_group_enabled_)
TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(event_handle_);
if (*category_group_enabled_) {
TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(category_group_enabled_,
name_, event_handle_);
}
}

} // namespace trace_event_internal
Loading

0 comments on commit dd37ea1

Please sign in to comment.