Skip to content

Commit 7e54451

Browse files
committed
Refactor event processing
1 parent c0cc729 commit 7e54451

File tree

1 file changed

+53
-78
lines changed

1 file changed

+53
-78
lines changed

collector/src/etw_parser.rs

Lines changed: 53 additions & 78 deletions
Original file line numberDiff line numberDiff line change
@@ -136,24 +136,9 @@ struct CSwitch {
136136
cpu: u8,
137137
}
138138

139-
#[derive(Debug, Eq, PartialEq)]
140-
enum Event {
141-
Pmc(Pmc),
142-
CSwitch(CSwitch),
143-
}
144-
145-
impl Event {
146-
fn timestamp(&self) -> u64 {
147-
match self {
148-
Event::Pmc(info) => info.timestamp,
149-
Event::CSwitch(info) => info.timestamp,
150-
}
151-
}
152-
}
153-
154139
#[derive(Debug, Eq, PartialEq)]
155140
struct EventData {
156-
events: Vec<Event>,
141+
events: Vec<(Pmc, CSwitch)>,
157142
watched_processes: HashSet<u64>,
158143
}
159144

@@ -188,6 +173,7 @@ fn parse_events(r: &mut dyn BufRead, headers: Vec<EventHeader>) -> anyhow::Resul
188173

189174
let mut events = Vec::new();
190175
let mut rustc_process = None;
176+
let mut last_pmc = None;
191177
let mut currently_watched_processes = HashSet::new();
192178
let mut all_watched_processes = HashSet::new();
193179

@@ -206,7 +192,7 @@ fn parse_events(r: &mut dyn BufRead, headers: Vec<EventHeader>) -> anyhow::Resul
206192
let line = String::from_utf8_lossy(&buffer[..]);
207193
let columns: Vec<_> = line.trim().split(',').collect();
208194

209-
events.push(match columns[0].trim() {
195+
match columns[0].trim() {
210196
PROCESS_START => {
211197
let process_name = columns[pstart_process_name].trim();
212198

@@ -236,8 +222,6 @@ fn parse_events(r: &mut dyn BufRead, headers: Vec<EventHeader>) -> anyhow::Resul
236222
}
237223
}
238224
}
239-
240-
continue;
241225
}
242226
PROCESS_END => {
243227
let process_name = columns[pend_process_name].trim();
@@ -252,16 +236,14 @@ fn parse_events(r: &mut dyn BufRead, headers: Vec<EventHeader>) -> anyhow::Resul
252236
break;
253237
}
254238
}
255-
256-
continue;
257239
}
258240
PMC => {
259-
Event::Pmc(Pmc {
241+
last_pmc = Some(Pmc {
260242
timestamp: columns[pmc_timestamp].trim().parse()?,
261243
thread_id: columns[pmc_thread_id].trim().parse()?,
262244
instructions_retired: columns[pmc_instructions_retired].trim().parse()?,
263245
total_cycles: columns[pmc_total_cycles].trim().parse()?,
264-
})
246+
});
265247
}
266248
CSWITCH => {
267249
let timestamp = columns[cswitch_timestamp].trim().parse()?;
@@ -274,23 +256,23 @@ fn parse_events(r: &mut dyn BufRead, headers: Vec<EventHeader>) -> anyhow::Resul
274256
// In this case, the previous Pmc event at this same timestamp isn't relevant.
275257
// There might not be a previous event if the CSwitch event occurs before the
276258
// Pmc events start recording.
277-
if let Some(previous_event) = events.pop() {
278-
assert!(matches!(previous_event, Event::Pmc(_)));
279-
assert_eq!(timestamp, previous_event.timestamp());
259+
if let Some(pmc) = &last_pmc {
260+
assert_eq!(timestamp, pmc.timestamp);
261+
last_pmc = None;
280262
}
281263

282264
continue;
283265
}
284266

285-
Event::CSwitch(CSwitch {
267+
events.push((std::mem::take(&mut last_pmc).unwrap(), CSwitch {
286268
timestamp,
287269
old_process_pid: old_pid,
288270
new_process_pid: new_pid,
289271
cpu: columns[cswitch_cpu].trim().parse()?,
290-
})
272+
}));
291273
}
292-
_ => continue
293-
});
274+
_ => { }
275+
}
294276
}
295277

296278
Ok(EventData {
@@ -360,24 +342,14 @@ impl From<&Pmc> for Counters {
360342

361343
fn process_events(event_data: EventData) -> anyhow::Result<Counters> {
362344
let EventData { events, watched_processes } = event_data;
363-
anyhow::ensure!(events.len() % 2 == 0, "events must have an even count");
364-
365-
let pmc_and_cswitch_events =
366-
events.chunks(2).map(|s| {
367-
match s {
368-
[Event::Pmc(pmc), Event::CSwitch(cswitch)] => Ok((pmc, cswitch)),
369-
other => anyhow::bail!("unexpected events: {:?}", other),
370-
}
371-
});
372345

373346
// We need to keep track of when the rustc process is running on a given CPU or not.
374347
// The basic algorithm here is to note the counters when rustc is moved onto the CPU and
375348
// then when it is moved off, add the delta to the running total.
376349
let mut total = Counters::default();
377350
let mut cpus = HashMap::new();
378351

379-
for result in pmc_and_cswitch_events {
380-
let (pmc, cswitch) = result?;
352+
for (pmc, cswitch) in events {
381353
anyhow::ensure!(pmc.timestamp == cswitch.timestamp, "event timestamps did not match");
382354

383355
// Handle if the rustc process (or a sub process) is moving on the cpu or off the CPU.
@@ -387,14 +359,14 @@ fn process_events(event_data: EventData) -> anyhow::Result<Counters> {
387359
if watched_processes.contains(&cswitch.old_process_pid) {
388360
if let Some(last_counters) = cpus.remove(&cswitch.cpu) {
389361
// record the delta between the starting and ending counters in the overall total
390-
total = total + (Counters::from(pmc) - last_counters);
362+
total = total + (Counters::from(&pmc) - last_counters);
391363
} else {
392364
anyhow::bail!("no existing record when rustc moved off CPU")
393365
}
394366
}
395367

396368
if watched_processes.contains(&cswitch.new_process_pid) {
397-
anyhow::ensure!(cpus.insert(cswitch.cpu, Counters::from(pmc)).is_none(), "existing record when rustc moved onto CPU");
369+
anyhow::ensure!(cpus.insert(cswitch.cpu, Counters::from(&pmc)).is_none(), "existing record when rustc moved onto CPU");
398370
}
399371
}
400372

@@ -404,7 +376,6 @@ fn process_events(event_data: EventData) -> anyhow::Result<Counters> {
404376
/// Given the path to the ETW results file, process it and calculate the
405377
/// hardware performance counter totals for the rustc process.
406378
pub fn parse_etw_file(path: &str) -> anyhow::Result<Counters> {
407-
log::trace!("path = {}", path);
408379
let mut file = std::io::BufReader::new(std::fs::File::open(path).unwrap());
409380

410381
let headers = parse_header(&mut file).unwrap();
@@ -419,7 +390,7 @@ pub fn parse_etw_file(path: &str) -> anyhow::Result<Counters> {
419390
#[cfg(test)]
420391
mod tests {
421392
use std::io::BufReader;
422-
use super::{Counters, CSwitch, Event, EventData, EventHeader, Pmc};
393+
use super::{Counters, CSwitch, EventData, EventHeader, Pmc};
423394

424395
#[test]
425396
fn parse_header() -> anyhow::Result<()> {
@@ -517,25 +488,26 @@ FirstReliableCSwitchEventTimeStamp, 6016
517488

518489
let expected = EventData {
519490
events: vec![
520-
Event::Pmc(Pmc {
491+
(Pmc {
521492
timestamp: 106082,
522493
thread_id: 15340,
523494
instructions_retired: 3184489,
524495
total_cycles: 3416818,
525-
}),
526-
Event::CSwitch(CSwitch {
496+
},
497+
CSwitch {
527498
timestamp: 106082,
528499
new_process_pid: 10612, // rustc.exe
529500
old_process_pid: 0, // Idle
530501
cpu: 0,
531502
}),
532-
Event::Pmc(Pmc {
503+
504+
(Pmc {
533505
timestamp: 107179,
534506
thread_id: 15340,
535507
instructions_retired: 4205942,
536508
total_cycles: 3779655,
537-
}),
538-
Event::CSwitch(CSwitch {
509+
},
510+
CSwitch {
539511
timestamp: 107179,
540512
new_process_pid: 0, // Idle
541513
old_process_pid: 10612, // rustc.exe
@@ -554,49 +526,52 @@ FirstReliableCSwitchEventTimeStamp, 6016
554526
fn process_events() -> anyhow::Result<()> {
555527
let events = EventData {
556528
events: vec![
557-
Event::Pmc(Pmc {
529+
(Pmc {
558530
timestamp: 106082,
559531
thread_id: 15340,
560532
instructions_retired: 3184489,
561533
total_cycles: 3416818,
562-
}),
563-
Event::CSwitch(CSwitch {
534+
},
535+
CSwitch {
564536
timestamp: 106082,
565537
old_process_pid: 0, // Idle
566538
new_process_pid: 10612, // rustc.exe
567539
cpu: 0,
568540
}),
569-
Event::Pmc(Pmc {
541+
542+
(Pmc {
570543
timestamp: 106085,
571544
thread_id: 99999,
572545
instructions_retired: 1000000,
573546
total_cycles: 20000,
574-
}),
575-
Event::CSwitch(CSwitch {
547+
},
548+
CSwitch {
576549
timestamp: 106085,
577550
old_process_pid: 1234, // foobar.exe
578551
new_process_pid: 10612, // rustc.exe
579552
cpu: 3,
580553
}),
581-
Event::Pmc(Pmc {
554+
555+
(Pmc {
582556
timestamp: 107179,
583557
thread_id: 15340,
584558
instructions_retired: 4205942,
585559
total_cycles: 3779655,
586-
}),
587-
Event::CSwitch(CSwitch {
560+
},
561+
CSwitch {
588562
timestamp: 107179,
589563
old_process_pid: 10612, // rustc.exe
590564
new_process_pid: 0, // Idle
591565
cpu: 0,
592566
}),
593-
Event::Pmc(Pmc {
567+
568+
(Pmc {
594569
timestamp: 1259540,
595570
thread_id: 99999,
596571
instructions_retired: 1540000,
597572
total_cycles: 23400,
598-
}),
599-
Event::CSwitch(CSwitch {
573+
},
574+
CSwitch {
600575
timestamp: 1259540,
601576
old_process_pid: 10612, // rustc.exe
602577
new_process_pid: 0, // Idle
@@ -621,65 +596,65 @@ FirstReliableCSwitchEventTimeStamp, 6016
621596
fn process_events_child_process() -> anyhow::Result<()> {
622597
let events = EventData {
623598
events: vec![
624-
Event::Pmc(Pmc {
599+
(Pmc {
625600
timestamp: 100,
626601
thread_id: 15340,
627602
instructions_retired: 1000,
628603
total_cycles: 5000,
629-
}),
630-
Event::CSwitch(CSwitch {
604+
},
605+
CSwitch {
631606
timestamp: 100,
632607
old_process_pid: 0, // Idle
633608
new_process_pid: 10612, // rustc.exe
634609
cpu: 0,
635610
}),
636611

637-
Event::Pmc(Pmc {
612+
(Pmc {
638613
timestamp: 200,
639614
thread_id: 99999,
640615
instructions_retired: 100_000,
641616
total_cycles: 300_000,
642-
}),
643-
Event::CSwitch(CSwitch {
617+
},
618+
CSwitch {
644619
timestamp: 200,
645620
old_process_pid: 0, // Idle
646621
new_process_pid: 12345, // rustc.exe -> link.exe
647622
cpu: 3,
648623
}),
649624

650-
Event::Pmc(Pmc {
625+
(Pmc {
651626
timestamp: 300,
652627
thread_id: 99999,
653628
instructions_retired: 200_000,
654629
total_cycles: 600_000,
655-
}),
656-
Event::CSwitch(CSwitch {
630+
},
631+
CSwitch {
657632
timestamp: 300,
658633
old_process_pid: 12345, // rustc.exe -> link.exe
659634
new_process_pid: 10612, // rustc.exe
660635
cpu: 3,
661636
}),
662637

663-
Event::Pmc(Pmc {
638+
(Pmc {
664639
timestamp: 400,
665640
thread_id: 15340,
666641
instructions_retired: 2500,
667642
total_cycles: 20000,
668-
}),
669-
Event::CSwitch(CSwitch {
643+
},
644+
CSwitch {
670645
timestamp: 400,
671646
old_process_pid: 10612, // rustc.exe
672647
new_process_pid: 0, // Idle
673648
cpu: 0
674649
}),
675650

676-
Event::Pmc(Pmc {
651+
(Pmc {
677652
timestamp: 500,
678653
thread_id: 15341,
679654
instructions_retired: 300_000,
680655
total_cycles: 700_000,
681-
}),
682-
Event::CSwitch(CSwitch {
656+
},
657+
CSwitch {
683658
timestamp: 500,
684659
old_process_pid: 10612, // rustc.exe
685660
new_process_pid: 0, // Idle

0 commit comments

Comments
 (0)