Skip to content

Commit

Permalink
Report trace buffer usage as number of events, not only percentage
Browse files Browse the repository at this point in the history
The total event count will be used later to show progress indicator when retrieving recorded events. The progress will be estimated as total events received divided by total buffer size.

BUG=426117

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

Cr-Commit-Position: refs/heads/master@{#304404}
  • Loading branch information
yury-s authored and Commit bot committed Nov 17, 2014
1 parent 5f52b6d commit d57ba6f
Show file tree
Hide file tree
Showing 15 changed files with 157 additions and 112 deletions.
14 changes: 11 additions & 3 deletions base/debug/trace_event_impl.cc
Original file line number Diff line number Diff line change
Expand Up @@ -1185,6 +1185,12 @@ void TraceLog::ThreadLocalEventBuffer::FlushWhileLocked() {
// find the generation mismatch and delete this buffer soon.
}

TraceLogStatus::TraceLogStatus() : event_capacity(0), event_count(0) {
}

TraceLogStatus::~TraceLogStatus() {
}

// static
TraceLog* TraceLog::GetInstance() {
return Singleton<TraceLog, LeakySingletonTraits<TraceLog> >::get();
Expand Down Expand Up @@ -1586,10 +1592,12 @@ bool TraceLog::HasEnabledStateObserver(EnabledStateObserver* listener) const {
return it != enabled_state_observer_list_.end();
}

float TraceLog::GetBufferPercentFull() const {
TraceLogStatus TraceLog::GetStatus() const {
AutoLock lock(lock_);
return static_cast<float>(static_cast<double>(logged_events_->Size()) /
logged_events_->Capacity());
TraceLogStatus result;
result.event_capacity = logged_events_->Capacity();
result.event_count = logged_events_->Size();
return result;
}

bool TraceLog::BufferIsFull() const {
Expand Down
10 changes: 8 additions & 2 deletions base/debug/trace_event_impl.h
Original file line number Diff line number Diff line change
Expand Up @@ -420,6 +420,13 @@ struct BASE_EXPORT TraceOptions {
bool enable_systrace;
};

struct BASE_EXPORT TraceLogStatus {
TraceLogStatus();
~TraceLogStatus();
size_t event_capacity;
size_t event_count;
};

class BASE_EXPORT TraceLog {
public:
enum Mode {
Expand Down Expand Up @@ -495,7 +502,7 @@ class BASE_EXPORT TraceLog {
void RemoveEnabledStateObserver(EnabledStateObserver* listener);
bool HasEnabledStateObserver(EnabledStateObserver* listener) const;

float GetBufferPercentFull() const;
TraceLogStatus GetStatus() const;
bool BufferIsFull() const;

// Not using base::Callback because of its limited by 7 parameters.
Expand Down Expand Up @@ -603,7 +610,6 @@ class BASE_EXPORT TraceLog {
static void DeleteForTesting();

// Allow tests to inspect TraceEvents.
size_t GetEventsSize() const { return logged_events_->Size(); }
TraceEvent* GetEventByHandle(TraceEventHandle handle);

void SetProcessID(int process_id);
Expand Down
9 changes: 3 additions & 6 deletions base/debug/trace_event_unittest.cc
Original file line number Diff line number Diff line change
Expand Up @@ -1366,8 +1366,7 @@ TEST_F(TraceEventTestFixture, AsyncBeginEndPointerMangling) {
TEST_F(TraceEventTestFixture, StaticStringVsString) {
TraceLog* tracer = TraceLog::GetInstance();
// Make sure old events are flushed:
EndTraceAndFlush();
EXPECT_EQ(0u, tracer->GetEventsSize());
EXPECT_EQ(0u, tracer->GetStatus().event_count);
const unsigned char* category_group_enabled =
TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED("cat");

Expand All @@ -1384,8 +1383,7 @@ TEST_F(TraceEventTestFixture, StaticStringVsString) {
TRACE_EVENT_PHASE_INSTANT, category_group_enabled, "name2", 0, 0,
"arg1", TRACE_STR_COPY("argval"),
"arg2", TRACE_STR_COPY("argval"));
size_t num_events = tracer->GetEventsSize();
EXPECT_GT(num_events, 1u);
EXPECT_GT(tracer->GetStatus().event_count, 1u);
const TraceEvent* event1 = tracer->GetEventByHandle(handle1);
const TraceEvent* event2 = tracer->GetEventByHandle(handle2);
ASSERT_TRUE(event1);
Expand Down Expand Up @@ -1414,8 +1412,7 @@ TEST_F(TraceEventTestFixture, StaticStringVsString) {
TRACE_EVENT_PHASE_INSTANT, category_group_enabled, "name2", 0, 0,
"arg1", TRACE_STR_COPY(str1),
"arg2", TRACE_STR_COPY(str2));
size_t num_events = tracer->GetEventsSize();
EXPECT_GT(num_events, 1u);
EXPECT_GT(tracer->GetStatus().event_count, 1u);
const TraceEvent* event1 = tracer->GetEventByHandle(handle1);
const TraceEvent* event2 = tracer->GetEventByHandle(handle2);
ASSERT_TRUE(event1);
Expand Down
10 changes: 4 additions & 6 deletions components/tracing/child_trace_message_filter.cc
Original file line number Diff line number Diff line change
Expand Up @@ -36,8 +36,7 @@ bool ChildTraceMessageFilter::OnMessageReceived(const IPC::Message& message) {
IPC_MESSAGE_HANDLER(TracingMsg_DisableMonitoring, OnDisableMonitoring)
IPC_MESSAGE_HANDLER(TracingMsg_CaptureMonitoringSnapshot,
OnCaptureMonitoringSnapshot)
IPC_MESSAGE_HANDLER(TracingMsg_GetTraceBufferPercentFull,
OnGetTraceBufferPercentFull)
IPC_MESSAGE_HANDLER(TracingMsg_GetTraceLogStatus, OnGetTraceLogStatus)
IPC_MESSAGE_HANDLER(TracingMsg_SetWatchEvent, OnSetWatchEvent)
IPC_MESSAGE_HANDLER(TracingMsg_CancelWatchEvent, OnCancelWatchEvent)
IPC_MESSAGE_UNHANDLED(handled = false)
Expand Down Expand Up @@ -105,10 +104,9 @@ void ChildTraceMessageFilter::OnCaptureMonitoringSnapshot() {
this));
}

void ChildTraceMessageFilter::OnGetTraceBufferPercentFull() {
float bpf = TraceLog::GetInstance()->GetBufferPercentFull();

sender_->Send(new TracingHostMsg_TraceBufferPercentFullReply(bpf));
void ChildTraceMessageFilter::OnGetTraceLogStatus() {
sender_->Send(new TracingHostMsg_TraceLogStatusReply(
TraceLog::GetInstance()->GetStatus()));
}

void ChildTraceMessageFilter::OnSetWatchEvent(const std::string& category_name,
Expand Down
2 changes: 1 addition & 1 deletion components/tracing/child_trace_message_filter.h
Original file line number Diff line number Diff line change
Expand Up @@ -39,7 +39,7 @@ class ChildTraceMessageFilter : public IPC::MessageFilter {
const std::string& options);
void OnDisableMonitoring();
void OnCaptureMonitoringSnapshot();
void OnGetTraceBufferPercentFull();
void OnGetTraceLogStatus();
void OnSetWatchEvent(const std::string& category_name,
const std::string& event_name);
void OnCancelWatchEvent();
Expand Down
15 changes: 10 additions & 5 deletions components/tracing/tracing_messages.h
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@
#include <vector>

#include "base/basictypes.h"
#include "base/debug/trace_event_impl.h"
#include "base/sync_socket.h"
#include "ipc/ipc_channel_handle.h"
#include "ipc/ipc_message_macros.h"
Expand All @@ -15,6 +16,11 @@

#define IPC_MESSAGE_START TracingMsgStart

IPC_STRUCT_TRAITS_BEGIN(base::debug::TraceLogStatus)
IPC_STRUCT_TRAITS_MEMBER(event_capacity)
IPC_STRUCT_TRAITS_MEMBER(event_count)
IPC_STRUCT_TRAITS_END()

// Sent to all child processes to enable trace event recording.
IPC_MESSAGE_CONTROL3(TracingMsg_BeginTracing,
std::string /* category_filter_str */,
Expand All @@ -37,7 +43,7 @@ IPC_MESSAGE_CONTROL0(TracingMsg_DisableMonitoring)
IPC_MESSAGE_CONTROL0(TracingMsg_CaptureMonitoringSnapshot)

// Sent to all child processes to get trace buffer fullness.
IPC_MESSAGE_CONTROL0(TracingMsg_GetTraceBufferPercentFull)
IPC_MESSAGE_CONTROL0(TracingMsg_GetTraceLogStatus)

// Sent to all child processes to set watch event.
IPC_MESSAGE_CONTROL2(TracingMsg_SetWatchEvent,
Expand Down Expand Up @@ -69,7 +75,6 @@ IPC_MESSAGE_CONTROL1(TracingHostMsg_TraceDataCollected,
IPC_MESSAGE_CONTROL1(TracingHostMsg_MonitoringTraceDataCollected,
std::string /*json trace data*/)

// Reply to TracingMsg_GetTraceBufferPercentFull.
IPC_MESSAGE_CONTROL1(TracingHostMsg_TraceBufferPercentFullReply,
float /*trace buffer percent full*/)

// Reply to TracingMsg_GetTraceLogStatus.
IPC_MESSAGE_CONTROL1(TracingHostMsg_TraceLogStatusReply,
base::debug::TraceLogStatus /*status of the trace log*/)
12 changes: 9 additions & 3 deletions content/browser/browser_shutdown_profile_dumper.cc
Original file line number Diff line number Diff line change
Expand Up @@ -29,14 +29,20 @@ BrowserShutdownProfileDumper::~BrowserShutdownProfileDumper() {
WriteTracesToDisc();
}

static float GetTraceBufferPercentFull() {
base::debug::TraceLogStatus status =
base::debug::TraceLog::GetInstance()->GetStatus();
return 100 * static_cast<float>(static_cast<double>(status.event_count) /
status.event_capacity);
}

void BrowserShutdownProfileDumper::WriteTracesToDisc() {
// Note: I have seen a usage of 0.000xx% when dumping - which fits easily.
// Since the tracer stops when the trace buffer is filled, we'd rather save
// what we have than nothing since we might see from the amount of events
// that caused the problem.
DVLOG(1) << "Flushing shutdown traces to disc. The buffer is %" <<
base::debug::TraceLog::GetInstance()->GetBufferPercentFull() <<
" full.";
DVLOG(1) << "Flushing shutdown traces to disc. The buffer is "
<< GetTraceBufferPercentFull() << "% full.";
DCHECK(!dump_file_);
dump_file_ = base::OpenFile(dump_file_name_, "w+");
if (!IsFileValid()) {
Expand Down
17 changes: 8 additions & 9 deletions content/browser/devtools/protocol/tracing_handler.cc
Original file line number Diff line number Diff line change
Expand Up @@ -142,8 +142,9 @@ void TracingHandler::OnRecordingEnabled(
client_->SendStartResponse(command, StartResponse::Create());
}

void TracingHandler::OnBufferUsage(float usage) {
client_->BufferUsage(BufferUsageParams::Create()->set_value(usage));
void TracingHandler::OnBufferUsage(float percent_full,
size_t approximate_event_count) {
client_->BufferUsage(BufferUsageParams::Create()->set_value(percent_full));
}

void TracingHandler::OnCategoriesReceived(
Expand Down Expand Up @@ -189,13 +190,11 @@ void TracingHandler::SetupTimer(double usage_reporting_interval) {
base::TimeDelta interval = base::TimeDelta::FromMilliseconds(
std::ceil(usage_reporting_interval));
buffer_usage_poll_timer_.reset(new base::Timer(
FROM_HERE,
interval,
base::Bind(
base::IgnoreResult(&TracingController::GetTraceBufferPercentFull),
base::Unretained(TracingController::GetInstance()),
base::Bind(&TracingHandler::OnBufferUsage,
weak_factory_.GetWeakPtr())),
FROM_HERE, interval,
base::Bind(base::IgnoreResult(&TracingController::GetTraceBufferUsage),
base::Unretained(TracingController::GetInstance()),
base::Bind(&TracingHandler::OnBufferUsage,
weak_factory_.GetWeakPtr())),
true));
buffer_usage_poll_timer_->Reset();
}
Expand Down
2 changes: 1 addition & 1 deletion content/browser/devtools/protocol/tracing_handler.h
Original file line number Diff line number Diff line change
Expand Up @@ -49,7 +49,7 @@ class TracingHandler {

private:
void OnRecordingEnabled(scoped_refptr<DevToolsProtocol::Command> command);
void OnBufferUsage(float usage);
void OnBufferUsage(float percent_full, size_t approximate_event_count);

void OnCategoriesReceived(scoped_refptr<DevToolsProtocol::Command> command,
const std::set<std::string>& category_set);
Expand Down
16 changes: 8 additions & 8 deletions content/browser/tracing/trace_message_filter.cc
Original file line number Diff line number Diff line change
Expand Up @@ -28,7 +28,7 @@ void TraceMessageFilter::OnChannelClosing() {
OnCaptureMonitoringSnapshotAcked();

if (is_awaiting_buffer_percent_full_ack_)
OnTraceBufferPercentFullReply(0.0f);
OnTraceLogStatusReply(base::debug::TraceLogStatus());

TracingControllerImpl::GetInstance()->RemoveTraceMessageFilter(this);
}
Expand All @@ -49,8 +49,8 @@ bool TraceMessageFilter::OnMessageReceived(const IPC::Message& message) {
OnMonitoringTraceDataCollected)
IPC_MESSAGE_HANDLER(TracingHostMsg_WatchEventMatched,
OnWatchEventMatched)
IPC_MESSAGE_HANDLER(TracingHostMsg_TraceBufferPercentFullReply,
OnTraceBufferPercentFullReply)
IPC_MESSAGE_HANDLER(TracingHostMsg_TraceLogStatusReply,
OnTraceLogStatusReply)
IPC_MESSAGE_UNHANDLED(handled = false)
IPC_END_MESSAGE_MAP()
return handled;
Expand Down Expand Up @@ -93,11 +93,11 @@ void TraceMessageFilter::SendCaptureMonitoringSnapshot() {
Send(new TracingMsg_CaptureMonitoringSnapshot);
}

void TraceMessageFilter::SendGetTraceBufferPercentFull() {
void TraceMessageFilter::SendGetTraceLogStatus() {
DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
DCHECK(!is_awaiting_buffer_percent_full_ack_);
is_awaiting_buffer_percent_full_ack_ = true;
Send(new TracingMsg_GetTraceBufferPercentFull);
Send(new TracingMsg_GetTraceLogStatus);
}

void TraceMessageFilter::SendSetWatchEvent(const std::string& category_name,
Expand Down Expand Up @@ -157,11 +157,11 @@ void TraceMessageFilter::OnWatchEventMatched() {
TracingControllerImpl::GetInstance()->OnWatchEventMatched();
}

void TraceMessageFilter::OnTraceBufferPercentFullReply(float percent_full) {
void TraceMessageFilter::OnTraceLogStatusReply(
const base::debug::TraceLogStatus& status) {
if (is_awaiting_buffer_percent_full_ack_) {
is_awaiting_buffer_percent_full_ack_ = false;
TracingControllerImpl::GetInstance()->OnTraceBufferPercentFullReply(
this, percent_full);
TracingControllerImpl::GetInstance()->OnTraceLogStatusReply(this, status);
} else {
NOTREACHED();
}
Expand Down
6 changes: 3 additions & 3 deletions content/browser/tracing/trace_message_filter.h
Original file line number Diff line number Diff line change
Expand Up @@ -31,7 +31,7 @@ class TraceMessageFilter : public BrowserMessageFilter {
const base::debug::TraceOptions& options);
void SendDisableMonitoring();
void SendCaptureMonitoringSnapshot();
void SendGetTraceBufferPercentFull();
void SendGetTraceLogStatus();
void SendSetWatchEvent(const std::string& category_name,
const std::string& event_name);
void SendCancelWatchEvent();
Expand All @@ -45,7 +45,7 @@ class TraceMessageFilter : public BrowserMessageFilter {
void OnEndTracingAck(const std::vector<std::string>& known_categories);
void OnCaptureMonitoringSnapshotAcked();
void OnWatchEventMatched();
void OnTraceBufferPercentFullReply(float percent_full);
void OnTraceLogStatusReply(const base::debug::TraceLogStatus& status);
void OnTraceDataCollected(const std::string& data);
void OnMonitoringTraceDataCollected(const std::string& data);

Expand All @@ -56,7 +56,7 @@ class TraceMessageFilter : public BrowserMessageFilter {
bool is_awaiting_end_ack_;
// Awaiting ack for previously sent SendCaptureMonitoringSnapshot
bool is_awaiting_capture_monitoring_snapshot_ack_;
// Awaiting ack for previously sent SendGetTraceBufferPercentFull
// Awaiting ack for previously sent SendGetTraceLogStatus
bool is_awaiting_buffer_percent_full_ack_;

DISALLOW_COPY_AND_ASSIGN(TraceMessageFilter);
Expand Down
Loading

0 comments on commit d57ba6f

Please sign in to comment.