// Copyright 2024 The Chromium Authors
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
#ifdef UNSAFE_BUFFERS_BUILD
// TODO(crbug.com/40285824): Remove this and convert code to safer constructs.
#pragma allow_unsafe_buffers
#endif
#include "components/tracing/common/etw_system_data_source_win.h"
#include <windows.h>
#include <evntcons.h>
#include <evntrace.h>
#include <utility>
#include "base/check.h"
#include "base/check_op.h"
#include "base/containers/buffer_iterator.h"
#include "base/containers/span.h"
#include "base/logging.h"
#include "base/task/thread_pool.h"
#include "base/win/event_trace_consumer.h"
#include "third_party/perfetto/include/perfetto/tracing/core/data_source_descriptor.h"
#include "third_party/perfetto/protos/perfetto/config/data_source_config.gen.h"
#include "third_party/perfetto/protos/perfetto/config/etw/etw_config.gen.h"
#include "third_party/perfetto/protos/perfetto/trace/etw/etw.pbzero.h"
#include "third_party/perfetto/protos/perfetto/trace/etw/etw_event.pbzero.h"
#include "third_party/perfetto/protos/perfetto/trace/etw/etw_event_bundle.pbzero.h"
namespace tracing {
namespace {
constexpr wchar_t kEtwSystemSessionName[] = L"org.chromium.etw_system";
constexpr uint8_t kCSwitchEventOpcode = 36;
ULONG EtwSystemFlagsFromEnum(
perfetto::protos::gen::EtwConfig::KernelFlag flag) {
switch (flag) {
case perfetto::protos::gen::EtwConfig::CSWITCH:
return EVENT_TRACE_FLAG_CSWITCH;
case perfetto::protos::gen::EtwConfig::DISPATCHER:
return EVENT_TRACE_FLAG_DISPATCHER;
}
}
} // namespace
class EtwSystemDataSource::Consumer
: public base::win::EtwTraceConsumerBase<Consumer> {
public:
static constexpr bool kEnableRecordMode = true;
static constexpr bool kRawTimestamp = true;
explicit Consumer(std::unique_ptr<perfetto::TraceWriterBase>);
~Consumer();
static void ProcessEventRecord(EVENT_RECORD* event_record);
static bool ProcessBuffer(EVENT_TRACE_LOGFILE* buffer);
void ConsumeEvents();
private:
void ProcessEventRecordImpl(const EVENT_HEADER* header,
const ETW_BUFFER_CONTEXT* buffer_context,
base::span<uint8_t> packet_data)
VALID_CONTEXT_REQUIRED(sequence_checker_);
std::unique_ptr<perfetto::TraceWriterBase> trace_writer_
GUARDED_BY_CONTEXT(sequence_checker_);
perfetto::TraceWriter::TracePacketHandle packet_handle_
GUARDED_BY_CONTEXT(sequence_checker_);
raw_ptr<perfetto::protos::pbzero::EtwTraceEventBundle> etw_events_
GUARDED_BY_CONTEXT(sequence_checker_);
SEQUENCE_CHECKER(sequence_checker_);
};
void EtwSystemDataSource::Register() {
perfetto::DataSourceDescriptor desc;
desc.set_name("org.chromium.etw_system");
perfetto::DataSource<EtwSystemDataSource>::Register(desc);
}
EtwSystemDataSource::EtwSystemDataSource()
: consume_task_runner_(base::ThreadPool::CreateSequencedTaskRunner(
{base::MayBlock(),
base::TaskShutdownBehavior::CONTINUE_ON_SHUTDOWN})),
consumer_{nullptr, base::OnTaskRunnerDeleter(nullptr)} {
DETACH_FROM_SEQUENCE(sequence_checker_);
}
EtwSystemDataSource::~EtwSystemDataSource() = default;
void EtwSystemDataSource::OnSetup(const SetupArgs& args) {
DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
data_source_config_ = *args.config;
}
void EtwSystemDataSource::OnStart(const StartArgs&) {
DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
if (data_source_config_.etw_config_raw().empty()) {
DLOG(ERROR) << "Skipping empty etw_config";
return;
}
perfetto::protos::gen::EtwConfig etw_config;
if (!etw_config.ParseFromString(data_source_config_.etw_config_raw())) {
DLOG(ERROR) << "Failed to parse etw_config";
return;
}
base::win::EtwTraceProperties ignore;
HRESULT hr =
base::win::EtwTraceController::Stop(kEtwSystemSessionName, &ignore);
if (FAILED(hr) && hr != HRESULT_FROM_WIN32(ERROR_WMI_INSTANCE_NOT_FOUND)) {
DLOG(ERROR) << "Failed to stop previous trace session: 0x" << std::hex
<< hr;
return;
}
// MD5 hash of "org.chromium.etw_system".
// 696e5ace-ff06-bfc6-4e63-0198f5b3bc99
static constexpr GUID kChromeEtwSystemGuid = {
0x696e5ace,
0xff06,
0xbfc6,
{0x4e, 0x63, 0x01, 0x98, 0xf5, 0xb3, 0xbc, 0x99}};
base::win::EtwTraceProperties prop;
EVENT_TRACE_PROPERTIES& p = *prop.get();
// QPC timer accuracy.
// https://learn.microsoft.com/en-us/windows/win32/etw/wnode-header
p.Wnode.ClientContext = 1;
// Windows 8 and later supports SystemTraceProvider in multiple
// private session that's not NT Kernel Logger.
// https://learn.microsoft.com/en-us/windows/win32/etw/configuring-and-starting-a-systemtraceprovider-session#enable-a-systemtraceprovider-session
prop.SetLoggerName(kEtwSystemSessionName);
p.Wnode.Guid = kChromeEtwSystemGuid;
p.LogFileMode = EVENT_TRACE_REAL_TIME_MODE | EVENT_TRACE_SYSTEM_LOGGER_MODE;
p.MinimumBuffers = 16;
p.BufferSize = 16;
p.FlushTimer = 1; // flush every second.
for (auto flag : etw_config.kernel_flags()) {
p.EnableFlags |= EtwSystemFlagsFromEnum(flag);
}
hr = etw_controller_.Start(kEtwSystemSessionName, &prop);
if (FAILED(hr)) {
DLOG(ERROR) << "Failed to start system trace session: 0x" << std::hex << hr;
return;
}
consumer_ = {new Consumer(CreateTraceWriter()),
base::OnTaskRunnerDeleter(consume_task_runner_)};
hr = consumer_->OpenRealtimeSession(kEtwSystemSessionName);
if (FAILED(hr)) {
etw_controller_.Stop(nullptr);
DLOG(ERROR) << "Failed to open system trace session: 0x" << std::hex << hr;
return;
}
consume_task_runner_->PostTask(
FROM_HERE, base::BindOnce(&EtwSystemDataSource::Consumer::ConsumeEvents,
base::Unretained(consumer_.get())));
}
void EtwSystemDataSource::OnStop(const StopArgs&) {
DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
etw_controller_.Stop(nullptr);
consumer_.reset();
}
EtwSystemDataSource::Consumer::Consumer(
std::unique_ptr<perfetto::TraceWriterBase> trace_writer)
: trace_writer_(std::move(trace_writer)) {
DETACH_FROM_SEQUENCE(sequence_checker_);
}
// Decodes a CSwitch Event.
// https://learn.microsoft.com/en-us/windows/win32/etw/cswitch
// Returns true on success, or false if `packet_data` is invalid.
bool EtwSystemDataSource::DecodeCSwitchEvent(
base::span<uint8_t> packet_data,
perfetto::protos::pbzero::EtwTraceEvent& event) {
// Size of CSwitch v2 in bytes.
static constexpr size_t kMinimumCSwitchLength = 24;
if (packet_data.size() < kMinimumCSwitchLength) {
return false;
}
base::BufferIterator<uint8_t> iterator{packet_data};
auto* c_switch = event.set_c_switch();
c_switch->set_new_thread_id(*iterator.Object<uint32_t>());
c_switch->set_old_thread_id(*iterator.Object<uint32_t>());
c_switch->set_new_thread_priority(*iterator.Object<int8_t>());
c_switch->set_old_thread_priority(*iterator.Object<int8_t>());
c_switch->set_previous_c_state(*iterator.Object<uint8_t>());
// SpareByte
std::ignore = iterator.Object<uint8_t>();
const int8_t* old_thread_wait_reason = iterator.Object<int8_t>();
if (!(*old_thread_wait_reason >= 0 &&
*old_thread_wait_reason <
perfetto::protos::pbzero::CSwitchEtwEvent::MAXIMUM_WAIT_REASON)) {
return false;
}
c_switch->set_old_thread_wait_reason(
static_cast<
perfetto::protos::pbzero::CSwitchEtwEvent::OldThreadWaitReason>(
*old_thread_wait_reason));
const int8_t* old_thread_wait_mode = iterator.Object<int8_t>();
if (!(*old_thread_wait_mode >= 0 &&
*old_thread_wait_mode <=
perfetto::protos::pbzero::CSwitchEtwEvent::USER_MODE)) {
return false;
}
c_switch->set_old_thread_wait_mode(
static_cast<perfetto::protos::pbzero::CSwitchEtwEvent::OldThreadWaitMode>(
*old_thread_wait_mode));
const int8_t* old_thread_state = iterator.Object<int8_t>();
if (!(*old_thread_state >= 0 &&
*old_thread_state <=
perfetto::protos::pbzero::CSwitchEtwEvent::DEFERRED_READY)) {
return false;
}
c_switch->set_old_thread_state(
static_cast<perfetto::protos::pbzero::CSwitchEtwEvent::OldThreadState>(
*old_thread_state));
c_switch->set_old_thread_wait_ideal_processor(*iterator.Object<int8_t>());
c_switch->set_new_thread_wait_time(*iterator.Object<uint32_t>());
return true;
}
EtwSystemDataSource::Consumer::~Consumer() = default;
void EtwSystemDataSource::Consumer::ConsumeEvents() {
DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
base::ScopedBlockingCall scoped_blocking(FROM_HERE,
base::BlockingType::MAY_BLOCK);
Consume();
}
void EtwSystemDataSource::Consumer::ProcessEventRecord(
EVENT_RECORD* event_record) {
// ThreadGuid, 3d6fa8d1-fe05-11d0-9dda-00c04fd7ba7c
// https://learn.microsoft.com/en-us/windows/win32/etw/nt-kernel-logger-constants
static constexpr GUID kThreadGuid = {
0x3d6fa8d1,
0xfe05,
0x11d0,
{0x9d, 0xda, 0x00, 0xc0, 0x4f, 0xd7, 0xba, 0x7c}};
Consumer* self = reinterpret_cast<Consumer*>(event_record->UserContext);
DCHECK_CALLED_ON_VALID_SEQUENCE(self->sequence_checker_);
if (IsEqualGUID(event_record->EventHeader.ProviderId, kThreadGuid)) {
self->ProcessEventRecordImpl(&event_record->EventHeader,
&event_record->BufferContext,
{static_cast<uint8_t*>(event_record->UserData),
event_record->UserDataLength});
}
}
void EtwSystemDataSource::Consumer::ProcessEventRecordImpl(
const EVENT_HEADER* header,
const ETW_BUFFER_CONTEXT* buffer_context,
base::span<uint8_t> packet_data) {
static const int64_t qpc_ticks_per_second = []() {
LARGE_INTEGER perf_counter_frequency = {};
::QueryPerformanceFrequency(&perf_counter_frequency);
CHECK_GT(perf_counter_frequency.QuadPart, 0);
return perf_counter_frequency.QuadPart;
}();
uint64_t now =
static_cast<uint64_t>(base::Time::kNanosecondsPerSecond *
static_cast<double>(header->TimeStamp.QuadPart) /
static_cast<double>(qpc_ticks_per_second));
if (!etw_events_) {
// Resetting the `packet_handle_` finalizes previous data.
packet_handle_ = trace_writer_->NewTracePacket();
packet_handle_->set_timestamp(now);
etw_events_ = packet_handle_->set_etw_events();
}
auto* event = etw_events_->add_event();
event->set_timestamp(now);
event->set_cpu(buffer_context->ProcessorIndex);
if (header->EventDescriptor.Opcode == kCSwitchEventOpcode) {
bool result = DecodeCSwitchEvent(packet_data, *event);
if (!result) {
DLOG(ERROR) << "Error decoding CSwitch Event";
}
}
}
bool EtwSystemDataSource::Consumer::ProcessBuffer(EVENT_TRACE_LOGFILE* buffer) {
Consumer* self = reinterpret_cast<Consumer*>(buffer->Context);
DCHECK_CALLED_ON_VALID_SEQUENCE(self->sequence_checker_);
self->etw_events_ = nullptr;
self->packet_handle_ = {};
return true;
}
} // namespace tracing
PERFETTO_DEFINE_DATA_SOURCE_STATIC_MEMBERS_WITH_ATTRS(
BASE_EXPORT,
tracing::EtwSystemDataSource);
// This should go after PERFETTO_DEFINE_DATA_SOURCE_STATIC_MEMBERS_WITH_ATTRS
// to avoid instantiation of type() template method before specialization.
std::unique_ptr<perfetto::TraceWriterBase>
tracing::EtwSystemDataSource::CreateTraceWriter() {
perfetto::internal::DataSourceStaticState* static_state =
perfetto::DataSourceHelper<EtwSystemDataSource>::type().static_state();
// EtwSystemDataSource disallows multiple instances, so our instance will
// always have index 0.
perfetto::internal::DataSourceState* instance_state = static_state->TryGet(0);
CHECK(instance_state);
return perfetto::internal::TracingMuxer::Get()->CreateTraceWriter(
static_state, data_source_config_.target_buffer(), instance_state,
perfetto::BufferExhaustedPolicy::kDrop);
}