Phase 1: Windows log collection + full-text search

Extends the agent, ingest, storage, api, and web with Windows Event
Log/ETW sourcing and Tantivy-backed free-text search, per the approved
Phase 1 plan.

- CLAUDE.md: materialized on disk (never existed as a file before) with
  a new Phase 1 "done looks like" section.
- agent: Windows Event Log (EvtSubscribe) and ETW sources, Windows
  service wrapper (install/uninstall/run-service), both feature- and
  target_os-gated so Linux builds/tests/clippy stay unaffected. Also
  fixed two pre-existing Phase 0 clippy gaps (dead-code on
  default-features-only builds, a type-inference edge case) found while
  testing every feature combination properly for the first time.
  UNVERIFIED on real Windows -- no Windows toolchain existed anywhere in
  the build environment; flagged prominently in three places.
- proto/ingest: new record_id field, assigned once server-side in
  ingest's gRPC front end so ClickHouse and Tantivy agree on the same ID
  for the same record.
- storage: record_id column + bloom filter index, verified against a
  live ClickHouse.
- search: new service, Tantivy index, rskafka consumer as an independent
  second consumer group on the same Redpanda topic ingest already reads.
- api/web: new /search endpoint and page, sharing the query page's
  result-table shape and component.
- hack/windows-fixture: sends realistic Windows-shaped data straight to
  ingest, so the pipeline's handling of it is verifiable without a
  Windows host.

Verified end-to-end on the live docker-compose stack: the same record_id
comes back from both /query and /search for the same log line, including
for windows-fixture's synthetic Windows Event Log data. Real bugs found
and fixed along the way: api/Dockerfile missing proto/ in its build
context, search's logs being completely silent (RUST_LOG gap), and
search/target/ missing from .gitignore/.dockerignore.
This commit is contained in:
2026-08-13 11:27:35 -07:00
parent fe854b1091
commit cd8aa290ca
66 changed files with 6084 additions and 171 deletions
+248
View File
@@ -0,0 +1,248 @@
//! ETW (Event Tracing for Windows) source: a real-time trace session
//! subscribed to specific provider GUIDs.
//!
//! UNVERIFIED, and the highest-risk file in this whole Windows integration
//! -- more so than windows_eventlog.rs. `EVENT_TRACE_PROPERTIES` requires
//! a variable-length buffer appended after the fixed struct (a classic C
//! "flexible array member" pattern for LoggerName), which is exactly the
//! kind of FFI layout detail most likely to be subtly wrong without a
//! Windows toolchain to actually compile and run this against. No Windows
//! target was available in the environment this was written in -- see the
//! module-level note in windows_eventlog.rs for what that means. Compile-
//! check and test this file specifically, first, before trusting any of
//! it.
//!
//! Providers are configured by **GUID**, not friendly name (e.g.
//! `"{22FB2CD6-0E7B-422B-A0C7-2FAD1FD0E716}"`) -- ETW's own
//! `EnableTraceEx2` API takes a GUID, not a name, and there's no simple
//! name-to-GUID resolution in the raw ETW API (that needs the separate TDH
//! provider-enumeration API, not implemented here). Look up a provider's
//! GUID with `logman query providers "<Friendly Name>"`.
//!
//! Message extraction here is deliberately limited to what's available
//! directly on `EVENT_RECORD`'s header (ProviderId, EventID, Level,
//! Keywords, timestamp, process/thread ID) -- no TDH-based property
//! decoding or message-template rendering (`TdhGetEventInformation`),
//! which is a meaningfully larger undertaking left for a follow-up. This
//! gives real session/provider/callback plumbing with a coarse message,
//! not full structured event decoding.
use super::{LineSender, RawLine};
use anyhow::{Context, Result};
use std::collections::HashMap;
use std::ffi::c_void;
use std::sync::mpsc as std_mpsc;
use std::time::{SystemTime, UNIX_EPOCH};
use tokio::sync::mpsc as tokio_mpsc;
use windows::core::{GUID, PCWSTR};
use windows::Win32::System::Diagnostics::Etw::{
CloseTrace, ControlTraceW, EnableTraceEx2, OpenTraceW, ProcessTrace, StartTraceW,
EVENT_CONTROL_CODE_ENABLE_PROVIDER, EVENT_RECORD, EVENT_TRACE_CONTROL_STOP,
EVENT_TRACE_LOGFILEW, EVENT_TRACE_LOGFILEW_0, EVENT_TRACE_LOGFILEW_1,
EVENT_TRACE_PROPERTIES, EVENT_TRACE_REAL_TIME_MODE, PROCESS_TRACE_MODE_EVENT_RECORD,
PROCESS_TRACE_MODE_REAL_TIME, TRACE_LEVEL_VERBOSE,
};
const SESSION_NAME: &str = "SentryAgentEtw";
pub async fn run(providers: &[String], tx: LineSender) -> Result<()> {
let providers = providers.to_vec();
let (blocking_tx, mut blocking_rx) = tokio_mpsc::channel::<RawLine>(256);
let handle = tokio::task::spawn_blocking(move || run_session(&providers, blocking_tx));
while let Some(line) = blocking_rx.recv().await {
if tx.send(line).await.is_err() {
break;
}
}
handle.await.context("ETW session task panicked")??;
Ok(())
}
fn to_wide(s: &str) -> Vec<u16> {
s.encode_utf16().chain(std::iter::once(0)).collect()
}
/// Thread-local-ish channel used to get the async sender into the
/// C-callable `event_record_callback`, which has a fixed extern "system"
/// signature and can't capture a closure. Set once per `run_session` call
/// before `ProcessTrace` starts invoking the callback.
thread_local! {
static CALLBACK_TX: std::cell::RefCell<Option<tokio_mpsc::Sender<RawLine>>> =
const { std::cell::RefCell::new(None) };
}
fn run_session(providers: &[String], tx: tokio_mpsc::Sender<RawLine>) -> Result<()> {
let guids: Vec<GUID> = providers
.iter()
.map(|p| GUID::try_from(p.as_str()).with_context(|| format!("invalid provider GUID: {p}")))
.collect::<Result<_>>()?;
unsafe {
let session_handle = start_session()?;
for guid in &guids {
enable_provider(session_handle, guid)?;
}
// ProcessTrace runs the consumer loop on *this* thread until
// CloseTrace is called (from the callback, or from another
// thread against the same handle) -- there's no separate
// "shutdown channel" here because the agent's top-level shutdown
// path currently aborts the whole spawn_blocking task rather
// than signaling sources to stop gracefully (same as the other
// sources today).
CALLBACK_TX.with(|cell| *cell.borrow_mut() = Some(tx));
let mut logfile = EVENT_TRACE_LOGFILEW::default();
let mut session_name_wide = to_wide(SESSION_NAME);
logfile.LoggerName = PCWSTR(session_name_wide.as_mut_ptr());
logfile.Anonymous1 = EVENT_TRACE_LOGFILEW_0 {
ProcessTraceMode: PROCESS_TRACE_MODE_REAL_TIME.0 | PROCESS_TRACE_MODE_EVENT_RECORD.0,
};
logfile.Anonymous2 = EVENT_TRACE_LOGFILEW_1 {
EventRecordCallback: Some(event_record_callback),
};
let trace_handle = OpenTraceW(&mut logfile);
if trace_handle.0 == u64::MAX as usize {
anyhow::bail!("OpenTraceW failed");
}
let result = ProcessTrace(&[trace_handle], None, None);
let _ = CloseTrace(trace_handle);
stop_session(session_handle);
result.ok().context("ProcessTrace failed")?;
}
Ok(())
}
unsafe fn start_session() -> Result<windows::Win32::System::Diagnostics::Etw::CONTROLTRACE_HANDLE> {
// EVENT_TRACE_PROPERTIES needs a trailing buffer (appended after the
// fixed struct) for the session's LoggerName -- this is the flexible-
// array-member pattern flagged in the module doc comment as the
// highest-risk detail in this file. LogFileNameOffset is left 0 (no
// log file; real-time only).
const LOGGER_NAME_CAPACITY: usize = 256;
let total_size = std::mem::size_of::<EVENT_TRACE_PROPERTIES>() + LOGGER_NAME_CAPACITY * 2;
let mut buffer = vec![0u8; total_size];
let props = buffer.as_mut_ptr() as *mut EVENT_TRACE_PROPERTIES;
(*props).Wnode.BufferSize = total_size as u32;
(*props).Wnode.Flags = windows::Win32::System::Diagnostics::Etw::WNODE_FLAG_TRACED_GUID;
(*props).LogFileMode = EVENT_TRACE_REAL_TIME_MODE;
(*props).LoggerNameOffset = std::mem::size_of::<EVENT_TRACE_PROPERTIES>() as u32;
let session_name_wide = to_wide(SESSION_NAME);
let mut session_handle = Default::default();
StartTraceW(
&mut session_handle,
PCWSTR(session_name_wide.as_ptr()),
props,
)
.ok()
.context("StartTraceW failed")?;
Ok(session_handle)
}
unsafe fn enable_provider(
session_handle: windows::Win32::System::Diagnostics::Etw::CONTROLTRACE_HANDLE,
guid: &GUID,
) -> Result<()> {
EnableTraceEx2(
session_handle,
guid,
EVENT_CONTROL_CODE_ENABLE_PROVIDER.0,
TRACE_LEVEL_VERBOSE as u8,
0,
0,
0,
None,
)
.ok()
.with_context(|| format!("EnableTraceEx2 failed for provider {guid:?}"))
}
unsafe fn stop_session(session_handle: windows::Win32::System::Diagnostics::Etw::CONTROLTRACE_HANDLE) {
let mut buffer = vec![0u8; std::mem::size_of::<EVENT_TRACE_PROPERTIES>() + 512];
let props = buffer.as_mut_ptr() as *mut EVENT_TRACE_PROPERTIES;
(*props).Wnode.BufferSize = buffer.len() as u32;
let _ = ControlTraceW(session_handle, PCWSTR::null(), props, EVENT_TRACE_CONTROL_STOP);
}
/// `extern "system"` callback ETW invokes per event during `ProcessTrace`.
/// Deliberately minimal: header fields only, no TDH property decoding
/// (see module doc comment).
unsafe extern "system" fn event_record_callback(record: *mut EVENT_RECORD) {
if record.is_null() {
return;
}
let record = &*record;
let header = &record.EventHeader;
let mut attributes = HashMap::new();
attributes.insert(
"etw.provider_guid".to_string(),
format!("{:?}", header.ProviderId),
);
attributes.insert("etw.event_id".to_string(), header.EventDescriptor.Id.to_string());
attributes.insert(
"etw.opcode".to_string(),
header.EventDescriptor.Opcode.to_string(),
);
attributes.insert(
"etw.task".to_string(),
header.EventDescriptor.Task.to_string(),
);
attributes.insert("etw.process_id".to_string(), header.ProcessId.to_string());
attributes.insert("etw.thread_id".to_string(), header.ThreadId.to_string());
let severity_hint = etw_level_to_syslog_severity(header.EventDescriptor.Level);
let timestamp_unix_nano = SystemTime::now()
.duration_since(UNIX_EPOCH)
.map(|d| d.as_nanos() as i64)
.unwrap_or(0);
// No TDH-based message rendering (see module doc comment) -- this is
// a coarse, structured summary rather than a human-authored message.
// Downstream (sentry_parser's raw-passthrough fallback) handles a
// non-RFC5424 line like this the same as any other raw line.
let message = format!(
"ETW event: provider={:?} id={} level={}",
header.ProviderId, header.EventDescriptor.Id, header.EventDescriptor.Level
);
let raw = RawLine {
line: message,
timestamp_unix_nano,
severity_hint,
extra_attributes: attributes,
};
CALLBACK_TX.with(|cell| {
if let Some(tx) = cell.borrow().as_ref() {
let _ = tx.blocking_send(raw);
}
});
}
/// Maps ETW `Level` (0=LogAlways/Verbose-ish through 5=Verbose, following
/// the same TRACE_LEVEL_* scale as windows_eventlog's Level values) onto
/// the syslog 0-7 scale, same reasoning as windows_eventlog.rs.
fn etw_level_to_syslog_severity(level: u8) -> Option<u8> {
match level {
1 => Some(2), // Critical -> crit
2 => Some(3), // Error -> err
3 => Some(4), // Warning -> warning
4 => Some(6), // Informational -> info
5 => Some(7), // Verbose -> debug
_ => None,
}
}
@@ -61,6 +61,7 @@ pub async fn run(path: &Path, from_beginning: bool, tx: LineSender) -> Result<()
line,
timestamp_unix_nano,
severity_hint: None,
extra_attributes: Default::default(),
})
.await
.is_err()
@@ -61,6 +61,7 @@ pub async fn run(unit: Option<&str>, tx: LineSender) -> Result<()> {
line: message,
timestamp_unix_nano,
severity_hint,
extra_attributes: Default::default(),
})
.await
.is_err()
+20 -4
View File
@@ -1,3 +1,4 @@
use std::collections::HashMap;
use tokio::sync::mpsc;
/// A raw line read from a source, plus whatever metadata the source itself
@@ -8,16 +9,31 @@ pub struct RawLine {
/// Unix epoch nanoseconds at time of read.
pub timestamp_unix_nano: i64,
/// Syslog severity (0-7) if the source already knows it independent of
/// the line's own content — e.g. journald's PRIORITY field. When set,
/// this takes precedence over whatever the RFC 5424 parser infers from
/// the message text, since it comes from a more authoritative place.
/// the line's own content — e.g. journald's PRIORITY field, or a
/// Windows Event Log Level mapped onto the same scale. When set, this
/// takes precedence over whatever the RFC 5424 parser infers from the
/// message text, since it comes from a more authoritative place.
pub severity_hint: Option<u8>,
/// Structured fields the source already knows, independent of the raw
/// message text — e.g. Windows Event Log's EventID/Provider/Channel.
/// Merged into the record's attributes alongside whatever the RFC 5424
/// parser extracts from `line`; on key collision, these win, since
/// they also come from a more authoritative place than text parsing.
/// Sources that have nothing to add (journald, file-tail) just leave
/// this empty.
pub extra_attributes: HashMap<String, String>,
}
pub type LineSender = mpsc::Sender<RawLine>;
#[cfg(feature = "journald")]
#[cfg(all(feature = "journald", target_os = "linux"))]
pub mod journald;
#[cfg(feature = "file-tail")]
pub mod file_tail;
#[cfg(all(feature = "windows-eventlog", target_os = "windows"))]
pub mod windows_eventlog;
#[cfg(all(feature = "etw", target_os = "windows"))]
pub mod etw;
@@ -0,0 +1,283 @@
//! Windows Event Log source via `EvtSubscribe`.
//!
//! UNVERIFIED: this module was written against the documented
//! EvtSubscribe/EvtNext/EvtRender API shape (the same pull-model pattern
//! Microsoft's own C++ samples use for subscriptions), but has not been
//! compiled or run on a real Windows host — no Windows target toolchain
//! was available in the environment this was written in (confirmed: only
//! x86_64-unknown-linux-gnu std was installed, no rustup, no way to even
//! `cargo check --target x86_64-pc-windows-*`). Treat this as a first
//! draft to compile-check and test for real before trusting it. See
//! /docs/phase-1-runbook.md for what's actually been verified vs. not.
use super::{LineSender, RawLine};
use anyhow::{Context, Result};
use std::collections::HashMap;
use std::time::{SystemTime, UNIX_EPOCH};
use tokio::sync::mpsc as tokio_mpsc;
use windows::core::PCWSTR;
use windows::Win32::Foundation::{ERROR_NO_MORE_ITEMS, WAIT_OBJECT_0};
use windows::Win32::System::EventLog::{
EvtClose, EvtNext, EvtRender, EvtRenderEventXml, EvtSubscribe, EVT_HANDLE,
EVT_SUBSCRIBE_TO_FUTURE_EVENTS,
};
use windows::Win32::System::Threading::{CreateEventW, WaitForSingleObject};
/// Tails one or more Windows Event Log channels. Runs the blocking
/// EvtSubscribe/EvtNext calls on a dedicated OS thread per channel (via
/// `spawn_blocking`) and forwards parsed lines back over `tx`, same shape
/// as the journald source's subprocess-reading loop.
pub async fn run(channels: &[String], tx: LineSender) -> Result<()> {
let channels = channels.to_vec();
let (blocking_tx, mut blocking_rx) = tokio_mpsc::channel::<RawLine>(256);
let handle = tokio::task::spawn_blocking(move || subscribe_all(&channels, blocking_tx));
while let Some(line) = blocking_rx.recv().await {
if tx.send(line).await.is_err() {
break; // receiver dropped, agent is shutting down
}
}
handle
.await
.context("windows event log subscription task panicked")??;
Ok(())
}
/// One `std::thread` per channel, each blocked in its own
/// wait-then-drain loop. Simpler and still correct for the common case of
/// 1-3 channels; a single `WaitForMultipleObjects`-based dispatcher would
/// scale better to many channels but isn't needed for Phase 1's default
/// three (Application/System/Security).
fn subscribe_all(channels: &[String], tx: tokio_mpsc::Sender<RawLine>) -> Result<()> {
let mut threads = Vec::with_capacity(channels.len());
for channel in channels {
let channel = channel.clone();
let tx = tx.clone();
threads.push(std::thread::spawn(move || subscribe_one(&channel, tx)));
}
for t in threads {
t.join()
.map_err(|_| anyhow::anyhow!("event log subscriber thread panicked"))??;
}
Ok(())
}
fn to_wide(s: &str) -> Vec<u16> {
s.encode_utf16().chain(std::iter::once(0)).collect()
}
fn subscribe_one(channel: &str, tx: tokio_mpsc::Sender<RawLine>) -> Result<()> {
unsafe {
let signal_event = CreateEventW(None, true, false, None)
.context("CreateEventW for subscription signal failed")?;
let channel_wide = to_wide(channel);
// NULL query (PCWSTR::null()) means "all events on this channel".
// No callback (None) -- pull model via the signal event instead,
// so this stays a plain loop rather than a Win32 callback that
// would need to cross back into the tokio runtime.
let subscription = EvtSubscribe(
None,
Some(signal_event),
PCWSTR(channel_wide.as_ptr()),
PCWSTR::null(),
None,
None,
None,
EVT_SUBSCRIBE_TO_FUTURE_EVENTS.0,
)
.context("EvtSubscribe failed")?;
loop {
let wait = WaitForSingleObject(signal_event, u32::MAX);
if wait != WAIT_OBJECT_0 {
anyhow::bail!("WaitForSingleObject on event log subscription failed");
}
loop {
let mut events: [EVT_HANDLE; 16] = [EVT_HANDLE::default(); 16];
let mut returned = 0u32;
let next = EvtNext(subscription, &mut events, 0, 0, &mut returned);
if let Err(err) = next {
if err.code() == ERROR_NO_MORE_ITEMS.into() {
break; // drained this batch; go back to waiting on the signal
}
return Err(err).context("EvtNext failed");
}
for &event in &events[..returned as usize] {
if let Some(raw) = render_event(event, channel) {
if tx.blocking_send(raw).is_err() {
let _ = EvtClose(event);
let _ = EvtClose(subscription);
return Ok(());
}
}
let _ = EvtClose(event);
}
}
}
}
}
fn render_event(event: EVT_HANDLE, channel: &str) -> Option<RawLine> {
unsafe {
let mut buffer_used = 0u32;
let mut property_count = 0u32;
// First call with a zero-length buffer to learn the required size.
let _ = EvtRender(
None,
event,
EvtRenderEventXml.0,
0,
None,
&mut buffer_used,
&mut property_count,
);
if buffer_used == 0 {
return None;
}
let mut buffer = vec![0u16; (buffer_used as usize).div_ceil(2)];
let rendered = EvtRender(
None,
event,
EvtRenderEventXml.0,
buffer_used,
Some(buffer.as_mut_ptr() as *mut _),
&mut buffer_used,
&mut property_count,
);
if rendered.is_err() {
return None;
}
let xml = String::from_utf16_lossy(&buffer);
let xml = xml.trim_end_matches('\0');
parse_event_xml(xml, channel)
}
}
/// Minimal, deliberately non-validating extraction of the fields Phase 1
/// needs from the rendered event XML: EventID, Provider, Level, Computer,
/// Windows' own EventRecordID, and a best-effort message. Not a full XML
/// parser in the schema-aware sense -- uses `quick-xml`'s streaming
/// reader to pull specific elements/attributes rather than hand-rolled
/// string search, but doesn't attempt full EventData/UserData schema
/// awareness across every provider's custom shape. Worth revisiting once
/// this is running against real events from real providers.
fn parse_event_xml(xml: &str, channel: &str) -> Option<RawLine> {
use quick_xml::events::Event as XmlEvent;
use quick_xml::reader::Reader;
let mut reader = Reader::from_str(xml);
reader.config_mut().trim_text(true);
let mut event_id = None;
let mut provider = None;
let mut level = None;
let mut computer = None;
let mut record_id = None;
let mut event_data_values: Vec<String> = Vec::new();
let mut current_tag: Option<String> = None;
let mut buf = Vec::new();
loop {
match reader.read_event_into(&mut buf) {
Ok(XmlEvent::Start(e)) | Ok(XmlEvent::Empty(e)) => {
let name = local_name(&e);
if name == "Provider" {
for attr in e.attributes().flatten() {
if attr.key.as_ref() == b"Name" {
provider = attr
.decode_and_unescape_value(reader.decoder())
.ok()
.map(|v| v.into_owned());
}
}
}
current_tag = Some(name);
}
Ok(XmlEvent::Text(t)) => {
let text = t.unescape().unwrap_or_default().into_owned();
match current_tag.as_deref() {
Some("EventID") => event_id = Some(text),
Some("Level") => level = text.parse::<u8>().ok(),
Some("Computer") => computer = Some(text),
Some("EventRecordID") => record_id = Some(text),
Some("Data") => event_data_values.push(text),
_ => {}
}
}
Ok(XmlEvent::Eof) => break,
Err(_) => return None,
_ => {}
}
buf.clear();
}
// <EventData> commonly holds one or more <Data Name="...">value</Data>
// elements rather than a single free-text message; joining them is a
// reasonable Phase 1 default until per-provider message templates are
// rendered properly. Real message-template rendering needs
// EvtFormatMessage against the provider's message-table resource --
// worth a follow-up, not required for a raw-passthrough-shaped record
// (sentry_parser's raw fallback handles this fine either way).
let message = if event_data_values.is_empty() {
xml.to_string()
} else {
event_data_values.join(" | ")
};
let mut attributes = HashMap::new();
if let Some(id) = &event_id {
attributes.insert("winevt.event_id".to_string(), id.clone());
}
if let Some(p) = provider {
attributes.insert("winevt.provider".to_string(), p);
}
attributes.insert("winevt.channel".to_string(), channel.to_string());
if let Some(c) = computer {
attributes.insert("winevt.computer".to_string(), c);
}
if let Some(r) = record_id {
attributes.insert("winevt.record_number".to_string(), r);
}
let severity_hint = level.and_then(windows_level_to_syslog_severity);
let timestamp_unix_nano = SystemTime::now()
.duration_since(UNIX_EPOCH)
.map(|d| d.as_nanos() as i64)
.unwrap_or(0);
Some(RawLine {
line: message,
timestamp_unix_nano,
severity_hint,
extra_attributes: attributes,
})
}
fn local_name(e: &quick_xml::events::BytesStart) -> String {
String::from_utf8_lossy(e.local_name().as_ref()).into_owned()
}
/// Maps Windows Event Log `Level` values (0=LogAlways, 1=Critical,
/// 2=Error, 3=Warning, 4=Informational, 5=Verbose) onto the same syslog
/// 0-7 severity scale `severity_hint` uses everywhere else in the agent,
/// so `main.rs`'s `to_pb_severity` needs no Windows-specific knowledge.
fn windows_level_to_syslog_severity(level: u8) -> Option<u8> {
match level {
1 => Some(2), // Critical -> crit
2 => Some(3), // Error -> err
3 => Some(4), // Warning -> warning
4 => Some(6), // Informational -> info
5 => Some(7), // Verbose -> debug
_ => None, // 0 (LogAlways) or unrecognized -- let the parser decide
}
}