samply 0.13.1

A command line profiler for macOS and Linux.
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221

use std::fs::File;
use std::os::windows::process::ExitStatusExt;
use std::process::ExitStatus;

use fxprof_processed_profile::{Profile, ReferenceTimestamp, SamplingInterval};

use super::etw_gecko;
use super::profile_context::ProfileContext;
use crate::server::{start_server_main, ServerProps};
use crate::shared::ctrl_c::CtrlC;
use crate::shared::included_processes::IncludedProcesses;
use crate::shared::recording_props::{ProfileCreationProps, RecordingMode, RecordingProps};
use crate::shared::save_profile::save_profile_to_file;
use crate::shared::symbol_props::SymbolProps;
use crate::windows::elevated_helper::ElevatedHelperSession;

// Hello intrepid explorer! You may be in this code because you'd like to extend something,
// or are trying to figure out how various ETW things work. It's not the easiest API!
//
// Here are some useful things I've discovered along the way:
// - The useful ETW events are part of the Kernel provider. This Kernel provider uses "classic" "MOF" events,
//   not new-style XML manifest events. This makes them a bit more of a pain to work with, and they're
//   poorly documented. Luckily, ferrisetw does a good job of pulling out the schema even for MOF events.
// - When trying to decipher ETW providers, opcodes, keywords, etc. there are two tools that
//   are useful:
//   - `logman query providers Microsoft-Windows-Kernel-Process` (or any other provider)
//     will give you info about the provider, including its keywords and values. Handy for a quick view.
//   - `Get-WinEvent -ListProvider "Microsoft-Windows-Kernel-Process` (PowerShell) will
//     give you more info. The returned object contains everything you may want to know, but you'll
//     need to print it. For example:
//       - `(Get-WinEvent -ListProvider "Microsoft-Windows-Kernel-Process").Opcodes`
//          will give you the opcodes.
//       - `(Get-WinEvent -ListProvider "Microsoft-Windows-Kernel-Process").Events[5]` will give you details about
//          that event.
//   - To get information about them, you can use `wbemtest`. Connect to the default store, and run a query like
//     `SELECT * FROM meta_class WHERE __THIS ISA "Win32_SystemTrace"`, Double click that to get object information,
//     including decompiling to MOF (the actual struct). There's a class hierarchy here.
//   - But not all events show up in `wbemtest`! A MOF file is in the Windows WDK, "Include/10.0.22621.0/km/wmicore.mof".
//     But it seems to only contain "32-bit" versions of events (e.g. addresses are u32, not u64). I can't find
//     a fully up to date .mof.
//   - There are some more complex StackWalk events (see etw.rs for info) but I haven't seen them.

pub fn start_recording(
    recording_mode: RecordingMode,
    recording_props: RecordingProps,
    profile_creation_props: ProfileCreationProps,
    symbol_props: SymbolProps,
    server_props: Option<ServerProps>,
) -> Result<ExitStatus, i32> {
    let timebase = std::time::SystemTime::now();
    let timebase = ReferenceTimestamp::from_system_time(timebase);

    let profile = Profile::new(
        profile_creation_props.profile_name(),
        timebase,
        SamplingInterval::from_nanos(1000000), // will be replaced with correct interval from file later
    );

    // Start xperf.
    let mut elevated_helper = ElevatedHelperSession::new(recording_props.output_file.clone())
        .unwrap_or_else(|e| panic!("Couldn't start elevated helper process: {e:?}"));
    elevated_helper
        .start_xperf(&recording_props, &profile_creation_props, &recording_mode)
        .unwrap();

    let included_processes = match recording_mode {
        RecordingMode::All => {
            let ctrl_c_receiver = CtrlC::observe_oneshot();
            eprintln!("Profiling all processes...");
            eprintln!("Press Ctrl+C to stop.");
            // TODO: Respect recording_props.time_limit, if specified
            // Wait for Ctrl+C.
            let _ = ctrl_c_receiver.blocking_recv();
            None
        }
        RecordingMode::Pid(pid) => {
            let ctrl_c_receiver = CtrlC::observe_oneshot();
            // TODO: check that process with this pid exists
            eprintln!("Profiling process with pid {pid}...");
            eprintln!("Press Ctrl+C to stop.");
            // TODO: Respect recording_props.time_limit, if specified
            // Wait for Ctrl+C.
            let _ = ctrl_c_receiver.blocking_recv();
            Some(IncludedProcesses {
                name_substrings: Vec::new(),
                pids: vec![pid],
            })
        }
        RecordingMode::Launch(process_launch_props) => {
            // Ignore Ctrl+C while the subcommand is running. The signal still reaches the process
            // under observation while we continue to record it.
            let mut ctrl_c_receiver = CtrlC::observe_oneshot();

            let mut pids = Vec::new();
            for _ in 0..process_launch_props.iteration_count {
                let mut child = std::process::Command::new(&process_launch_props.command_name);
                child.args(&process_launch_props.args);
                child.envs(process_launch_props.env_vars.iter().map(|(k, v)| (k, v)));
                let mut child = child.spawn().unwrap();

                pids.push(child.id());

                // Wait for the child to exit.
                //
                // TODO: Do the child waiting and the xperf control on different threads,
                // so that we can stop xperf immediately if we receive Ctrl+C. If they're on
                // the same thread, we might be blocking in wait() for a long time, and the
                // longer we take to handle Ctrl+C, the higher the chance that the user might
                // press Ctrl+C again, which would immediately terminate this process and not
                // give us a chance to stop xperf.
                let exit_status = child.wait().unwrap();
                if !exit_status.success() {
                    eprintln!(
                        "Skipping remaining iterations due to non-success exit status: \"{}\"",
                        exit_status
                    );
                    break;
                }
            }

            // The launched subprocess is done. From now on, we want to terminate if the user presses Ctrl+C.
            ctrl_c_receiver.close();

            Some(IncludedProcesses {
                name_substrings: Vec::new(),
                pids,
            })
        }
    };

    eprintln!("Stopping xperf...");

    let (kernel_output_file, user_output_file) = elevated_helper
        .stop_xperf()
        .expect("Should have produced a merged ETL file");

    elevated_helper.shutdown();

    eprintln!("Processing ETL trace...");

    let output_file = recording_props.output_file.clone();

    let arch = profile_creation_props
        .override_arch
        .clone()
        .unwrap_or(get_native_arch().to_string());

    let unstable_presymbolicate = profile_creation_props.unstable_presymbolicate;
    let mut context =
        ProfileContext::new(profile, &arch, included_processes, profile_creation_props);
    let extra_etls = match &user_output_file {
        Some(user_etl) => vec![user_etl.clone()],
        None => Vec::new(),
    };
    etw_gecko::process_etl_files(&mut context, &kernel_output_file, &extra_etls);

    if let Some(win_version) = winver::WindowsVersion::detect() {
        context.set_os_name(&format!("Windows {win_version}"))
    }

    let profile = context.finish();

    if !recording_props.keep_etl {
        std::fs::remove_file(&kernel_output_file).unwrap_or_else(|_| {
            panic!(
                "Failed to delete ETL file {:?}",
                kernel_output_file.to_str().unwrap()
            )
        });
        if let Some(user_output_file) = &user_output_file {
            std::fs::remove_file(user_output_file).unwrap_or_else(|_| {
                panic!(
                    "Failed to delete ETL file {:?}",
                    user_output_file.to_str().unwrap()
                )
            });
        }
    } else {
        eprintln!("ETL path: {}", kernel_output_file.to_str().unwrap());
        if let Some(user_output_file) = &user_output_file {
            eprintln!("User ETL path: {}", user_output_file.to_str().unwrap());
        }
    }

    save_profile_to_file(&profile, &output_file).expect("Couldn't write JSON");

    if unstable_presymbolicate {
        crate::shared::symbol_precog::presymbolicate(
            &profile,
            &output_file.with_extension("syms.json"),
        );
    }

    // then fire up the server for the profiler front end, if not save-only
    if let Some(server_props) = server_props {
        let libinfo_map = crate::profile_json_preparse::parse_libinfo_map_from_profile_file(
            File::open(&output_file).expect("Couldn't open file we just wrote"),
            &output_file,
        )
        .expect("Couldn't parse libinfo map from profile file");

        start_server_main(&output_file, server_props, symbol_props, libinfo_map);
    }

    Ok(ExitStatus::from_raw(0))
}

#[cfg(target_arch = "x86")]
fn get_native_arch() -> &'static str {
    "x86"
}

#[cfg(target_arch = "x86_64")]
fn get_native_arch() -> &'static str {
    "x86_64"
}

#[cfg(target_arch = "aarch64")]
fn get_native_arch() -> &'static str {
    "arm64"
}