Skip to content

Commit

Permalink
[tracing] Avoid race condition on sync observers removal.
Browse files Browse the repository at this point in the history 
Observers list cannot be iterated out of a lock, as then
the callback can be invoked on an observer that had just been removed
and deleted.

That comes at a cost of not allowing self removal of observers.
None of the clients seems to utilize that feature so far.
It could technically be implemented, but it's hard to justify the
complexity it would bring.

Change-Id: Iaf6374e5344a2fc774246829648bd5c71740b6f5
Reviewed-on: https://chromium-review.googlesource.com/1237250
Reviewed-by: Jochen Eisinger <jochen@chromium.org>
Reviewed-by: Dmitry Gozman <dgozman@chromium.org>
Reviewed-by: oysteine <oysteine@chromium.org>
Reviewed-by: Siddhartha S <ssid@chromium.org>
Commit-Queue: Alexei Filippov <alph@chromium.org>
Cr-Commit-Position: refs/heads/master@{#594186}
  • Loading branch information
@a1ph
a1ph authored and Commit Bot committed Sep 26, 2018
1 parent af51b28 commit 05cd86c
Show file tree
Hide file tree
Showing 4 changed files with 128 additions and 136 deletions.
4 changes: 3 additions & 1 deletion base/trace_event/trace_event_unittest.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1334,7 +1334,9 @@ class SelfRemovingEnabledStateObserver
}
};

TEST_F(TraceEventTestFixture, SelfRemovingObserver) {
// Self removing observers are not supported at the moment.
// TODO(alph): We could add support once we have recursive locks.
TEST_F(TraceEventTestFixture, DISABLED_SelfRemovingObserver) {
ASSERT_EQ(0u, TraceLog::GetInstance()->GetObserverCountForTest());

SelfRemovingEnabledStateObserver observer;
Expand Down
231 changes: 108 additions & 123 deletions base/trace_event/trace_log.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -370,7 +370,6 @@ void TraceLog::ResetForTesting() {
TraceLog::TraceLog()
: enabled_modes_(0),
num_traces_recorded_(0),
dispatching_to_observer_list_(false),
process_sort_index_(0),
process_id_hash_(0),
process_id_(0),
Expand Down Expand Up @@ -571,95 +570,90 @@ void TraceLog::SetEnabled(const TraceConfig& trace_config,
uint8_t modes_to_enable) {
DCHECK(trace_config.process_filter_config().IsEnabled(process_id_));

std::vector<EnabledStateObserver*> observer_list;
std::map<AsyncEnabledStateObserver*, RegisteredAsyncObserver> observer_map;
{
AutoLock lock(lock_);
AutoLock lock(lock_);

// Can't enable tracing when Flush() is in progress.
DCHECK(!flush_task_runner_);
// Can't enable tracing when Flush() is in progress.
DCHECK(!flush_task_runner_);

InternalTraceOptions new_options =
GetInternalOptionsFromTraceConfig(trace_config);
InternalTraceOptions new_options =
GetInternalOptionsFromTraceConfig(trace_config);

InternalTraceOptions old_options = trace_options();
InternalTraceOptions old_options = trace_options();

if (dispatching_to_observer_list_) {
// TODO(ssid): Change to NOTREACHED after fixing crbug.com/625170.
DLOG(ERROR)
<< "Cannot manipulate TraceLog::Enabled state from an observer.";
return;
}

// Clear all filters from previous tracing session. These filters are not
// cleared at the end of tracing because some threads which hit trace event
// when disabling, could try to use the filters.
if (!enabled_modes_)
GetCategoryGroupFilters().clear();

// Update trace config for recording.
const bool already_recording = enabled_modes_ & RECORDING_MODE;
if (modes_to_enable & RECORDING_MODE) {
if (already_recording) {
// TODO(ssid): Stop suporting enabling of RECODING_MODE when already
// enabled crbug.com/625170.
DCHECK_EQ(new_options, old_options) << "Attempting to re-enable "
"tracing with a different set "
"of options.";
trace_config_.Merge(trace_config);
} else {
trace_config_ = trace_config;
}
}
if (dispatching_to_observers_) {
// TODO(ssid): Change to NOTREACHED after fixing crbug.com/625170.
DLOG(ERROR)
<< "Cannot manipulate TraceLog::Enabled state from an observer.";
return;
}

// Update event filters only if filtering was not enabled.
if (modes_to_enable & FILTERING_MODE && enabled_event_filters_.empty()) {
DCHECK(!trace_config.event_filters().empty());
enabled_event_filters_ = trace_config.event_filters();
// Clear all filters from previous tracing session. These filters are not
// cleared at the end of tracing because some threads which hit trace event
// when disabling, could try to use the filters.
if (!enabled_modes_)
GetCategoryGroupFilters().clear();

// Update trace config for recording.
const bool already_recording = enabled_modes_ & RECORDING_MODE;
if (modes_to_enable & RECORDING_MODE) {
if (already_recording) {
// TODO(ssid): Stop supporting enabling of RECORDING_MODE when already
// enabled crbug.com/625170.
DCHECK_EQ(new_options, old_options) << "Attempting to re-enable "
"tracing with a different set "
"of options.";
trace_config_.Merge(trace_config);
} else {
trace_config_ = trace_config;
}
// Keep the |trace_config_| updated with only enabled filters in case anyone
// tries to read it using |GetCurrentTraceConfig| (even if filters are
// empty).
trace_config_.SetEventFilters(enabled_event_filters_);
}

enabled_modes_ |= modes_to_enable;
UpdateCategoryRegistry();
// Update event filters only if filtering was not enabled.
if (modes_to_enable & FILTERING_MODE && enabled_event_filters_.empty()) {
DCHECK(!trace_config.event_filters().empty());
enabled_event_filters_ = trace_config.event_filters();
}
// Keep the |trace_config_| updated with only enabled filters in case anyone
// tries to read it using |GetCurrentTraceConfig| (even if filters are
// empty).
trace_config_.SetEventFilters(enabled_event_filters_);

// Do not notify observers or create trace buffer if only enabled for
// filtering or if recording was already enabled.
if (!(modes_to_enable & RECORDING_MODE) || already_recording)
return;
enabled_modes_ |= modes_to_enable;
UpdateCategoryRegistry();

// Discard events if new trace options are different. Reducing trace buffer
// size is not supported while already recording, so only replace trace
// buffer if we were not already recording.
if (new_options != old_options ||
(trace_config_.GetTraceBufferSizeInEvents() && !already_recording)) {
subtle::NoBarrier_Store(&trace_options_, new_options);
UseNextTraceBuffer();
}
// Do not notify observers or create trace buffer if only enabled for
// filtering or if recording was already enabled.
if (!(modes_to_enable & RECORDING_MODE) || already_recording)
return;

num_traces_recorded_++;
// Discard events if new trace options are different. Reducing trace buffer
// size is not supported while already recording, so only replace trace
// buffer if we were not already recording.
if (new_options != old_options ||
(trace_config_.GetTraceBufferSizeInEvents() && !already_recording)) {
subtle::NoBarrier_Store(&trace_options_, new_options);
UseNextTraceBuffer();
}

UpdateCategoryRegistry();
num_traces_recorded_++;

dispatching_to_observer_list_ = true;
observer_list = enabled_state_observer_list_;
observer_map = async_observers_;
}
// Notify observers outside the lock in case they trigger trace events.
for (EnabledStateObserver* observer : observer_list)
observer->OnTraceLogEnabled();
for (const auto& it : observer_map) {
it.second.task_runner->PostTask(
FROM_HERE, BindOnce(&AsyncEnabledStateObserver::OnTraceLogEnabled,
it.second.observer));
}
UpdateCategoryRegistry();

dispatching_to_observers_ = true;
{
AutoLock lock(lock_);
dispatching_to_observer_list_ = false;
// Notify observers outside of the thread events lock, so they can trigger
// trace events.
AutoUnlock unlock(lock_);
AutoLock lock2(observers_lock_);
for (EnabledStateObserver* observer : enabled_state_observers_)
observer->OnTraceLogEnabled();
for (const auto& it : async_observers_) {
it.second.task_runner->PostTask(
FROM_HERE, BindOnce(&AsyncEnabledStateObserver::OnTraceLogEnabled,
it.second.observer));
}
}
dispatching_to_observers_ = false;
}

void TraceLog::SetArgumentFilterPredicate(
Expand Down Expand Up @@ -710,7 +704,7 @@ void TraceLog::SetDisabledWhileLocked(uint8_t modes_to_disable) {
if (!(enabled_modes_ & modes_to_disable))
return;

if (dispatching_to_observer_list_) {
if (dispatching_to_observers_) {
// TODO(ssid): Change to NOTREACHED after fixing crbug.com/625170.
DLOG(ERROR)
<< "Cannot manipulate TraceLog::Enabled state from an observer.";
Expand Down Expand Up @@ -739,58 +733,68 @@ void TraceLog::SetDisabledWhileLocked(uint8_t modes_to_disable) {
// Remove metadata events so they will not get added to a subsequent trace.
metadata_events_.clear();

dispatching_to_observer_list_ = true;
std::vector<EnabledStateObserver*> observer_list =
enabled_state_observer_list_;
std::map<AsyncEnabledStateObserver*, RegisteredAsyncObserver> observer_map =
async_observers_;

dispatching_to_observers_ = true;
{
// Dispatch to observers outside the lock in case the observer triggers a
// trace event.
// Release trace events lock, so observers can trigger trace events.
AutoUnlock unlock(lock_);
for (EnabledStateObserver* observer : observer_list)
observer->OnTraceLogDisabled();
for (const auto& it : observer_map) {
AutoLock lock2(observers_lock_);
for (auto* it : enabled_state_observers_)
it->OnTraceLogDisabled();
for (const auto& it : async_observers_) {
it.second.task_runner->PostTask(
FROM_HERE, BindOnce(&AsyncEnabledStateObserver::OnTraceLogDisabled,
it.second.observer));
}
}
dispatching_to_observer_list_ = false;
dispatching_to_observers_ = false;
}

int TraceLog::GetNumTracesRecorded() {
AutoLock lock(lock_);
if (!IsEnabled())
return -1;
return num_traces_recorded_;
return IsEnabled() ? num_traces_recorded_ : -1;
}

void TraceLog::AddEnabledStateObserver(EnabledStateObserver* listener) {
AutoLock lock(lock_);
enabled_state_observer_list_.push_back(listener);
AutoLock lock(observers_lock_);
enabled_state_observers_.push_back(listener);
}

void TraceLog::RemoveEnabledStateObserver(EnabledStateObserver* listener) {
AutoLock lock(lock_);
std::vector<EnabledStateObserver*>::iterator it =
std::find(enabled_state_observer_list_.begin(),
enabled_state_observer_list_.end(), listener);
if (it != enabled_state_observer_list_.end())
enabled_state_observer_list_.erase(it);
AutoLock lock(observers_lock_);
enabled_state_observers_.erase(
std::remove(enabled_state_observers_.begin(),
enabled_state_observers_.end(), listener),
enabled_state_observers_.end());
}

void TraceLog::AddOwnedEnabledStateObserver(
std::unique_ptr<EnabledStateObserver> listener) {
AutoLock lock(lock_);
enabled_state_observer_list_.push_back(listener.get());
AutoLock lock(observers_lock_);
enabled_state_observers_.push_back(listener.get());
owned_enabled_state_observer_copy_.push_back(std::move(listener));
}

bool TraceLog::HasEnabledStateObserver(EnabledStateObserver* listener) const {
AutoLock lock(lock_);
return ContainsValue(enabled_state_observer_list_, listener);
AutoLock lock(observers_lock_);
return ContainsValue(enabled_state_observers_, listener);
}

void TraceLog::AddAsyncEnabledStateObserver(
WeakPtr<AsyncEnabledStateObserver> listener) {
AutoLock lock(observers_lock_);
async_observers_.emplace(listener.get(), RegisteredAsyncObserver(listener));
}

void TraceLog::RemoveAsyncEnabledStateObserver(
AsyncEnabledStateObserver* listener) {
AutoLock lock(observers_lock_);
async_observers_.erase(listener);
}

bool TraceLog::HasAsyncEnabledStateObserver(
AsyncEnabledStateObserver* listener) const {
AutoLock lock(observers_lock_);
return ContainsKey(async_observers_, listener);
}

TraceLogStatus TraceLog::GetStatus() const {
Expand Down Expand Up @@ -1724,7 +1728,7 @@ void TraceLog::SetTimeOffset(TimeDelta offset) {
}

size_t TraceLog::GetObserverCountForTest() const {
return enabled_state_observer_list_.size();
return enabled_state_observers_.size();
}

void TraceLog::SetCurrentThreadBlocksMessageLoop() {
Expand Down Expand Up @@ -1785,25 +1789,6 @@ void ConvertableToTraceFormat::EstimateTraceMemoryOverhead(
sizeof(*this));
}

void TraceLog::AddAsyncEnabledStateObserver(
WeakPtr<AsyncEnabledStateObserver> listener) {
AutoLock lock(lock_);
async_observers_.insert(
std::make_pair(listener.get(), RegisteredAsyncObserver(listener)));
}

void TraceLog::RemoveAsyncEnabledStateObserver(
AsyncEnabledStateObserver* listener) {
AutoLock lock(lock_);
async_observers_.erase(listener);
}

bool TraceLog::HasAsyncEnabledStateObserver(
AsyncEnabledStateObserver* listener) const {
AutoLock lock(lock_);
return ContainsKey(async_observers_, listener);
}

} // namespace trace_event
} // namespace base

Expand Down
11 changes: 8 additions & 3 deletions base/trace_event/trace_log.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -125,7 +125,9 @@ class BASE_EXPORT TraceLog : public MemoryDumpProvider {
// TraceLog::IsEnabled() is false at this point.
virtual void OnTraceLogDisabled() = 0;
};
// Adds an observer. Cannot be called from within the observer callback.
void AddEnabledStateObserver(EnabledStateObserver* listener);
// Removes an observer. Cannot be called from within the observer callback.
void RemoveEnabledStateObserver(EnabledStateObserver* listener);
// Adds an observer that is owned by TraceLog. This is useful for agents that
// implement tracing feature that needs to stay alive as long as TraceLog
Expand Down Expand Up @@ -478,12 +480,15 @@ class BASE_EXPORT TraceLog : public MemoryDumpProvider {
int num_traces_recorded_;
std::unique_ptr<TraceBuffer> logged_events_;
std::vector<std::unique_ptr<TraceEvent>> metadata_events_;
bool dispatching_to_observer_list_;
std::vector<EnabledStateObserver*> enabled_state_observer_list_;

// The lock protects observers access.
mutable Lock observers_lock_;
bool dispatching_to_observers_ = false;
std::vector<EnabledStateObserver*> enabled_state_observers_;
std::map<AsyncEnabledStateObserver*, RegisteredAsyncObserver>
async_observers_;
// Manages ownership of the owned observers. The owned observers will also be
// added to |enabled_state_observer_list_|.
// added to |enabled_state_observers_|.
std::vector<std::unique_ptr<EnabledStateObserver>>
owned_enabled_state_observer_copy_;

Expand Down
18 changes: 9 additions & 9 deletions gin/v8_platform.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -60,7 +60,14 @@ class ConvertableToTraceFormatWrapper final
class EnabledStateObserverImpl final
: public base::trace_event::TraceLog::EnabledStateObserver {
public:
EnabledStateObserverImpl() = default;
EnabledStateObserverImpl() {
base::trace_event::TraceLog::GetInstance()->AddEnabledStateObserver(this);
}

~EnabledStateObserverImpl() override {
base::trace_event::TraceLog::GetInstance()->RemoveEnabledStateObserver(
this);
}

void OnTraceLogEnabled() final {
base::AutoLock lock(mutex_);
Expand All @@ -80,12 +87,9 @@ class EnabledStateObserverImpl final
{
base::AutoLock lock(mutex_);
DCHECK(!observers_.count(observer));
if (observers_.empty()) {
base::trace_event::TraceLog::GetInstance()->AddEnabledStateObserver(
this);
}
observers_.insert(observer);
}

// Fire the observer if recording is already in progress.
if (base::trace_event::TraceLog::GetInstance()->IsEnabled())
observer->OnTraceEnabled();
Expand All @@ -95,10 +99,6 @@ class EnabledStateObserverImpl final
base::AutoLock lock(mutex_);
DCHECK(observers_.count(observer) == 1);
observers_.erase(observer);
if (observers_.empty()) {
base::trace_event::TraceLog::GetInstance()->RemoveEnabledStateObserver(
this);
}
}

private:
Expand Down

0 comments on commit 05cd86c

Please sign in to comment.