wasmtime_jit/profiling/
jitdump_linux.rs

1//! Support for jitdump files which can be used by perf for profiling jitted code.
2//! Spec definitions for the output format is as described here:
3//! <https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/tools/perf/Documentation/jitdump-specification.txt>
4//!
5//! Usage Example:
6//!     Record
7//!         sudo perf record -k 1 -e instructions:u target/debug/wasmtime -g --profile=jitdump test.wasm
8//!     Combine
9//!         sudo perf inject -v -j -i perf.data -o perf.jit.data
10//!     Report
11//!         sudo perf report -i perf.jit.data -F+period,srcline
12//! Note: For descriptive results, the WASM file being executed should contain dwarf debug data
13
14use crate::{CompiledModule, ProfilingAgent};
15use anyhow::Result;
16use object::{Object, ObjectSection};
17use std::sync::Mutex;
18use std::{borrow, mem, process};
19use target_lexicon::Architecture;
20use wasmtime_environ::EntityRef;
21use wasmtime_jit_debug::perf_jitdump::*;
22
23use object::elf;
24
25/// Interface for driving the creation of jitdump files
26pub struct JitDumpAgent {
27    /// Flag for experimenting with dumping code load record
28    /// after each function (true) or after each module. This
29    /// flag is currently set to true.
30    dump_funcs: bool,
31}
32
33/// Process-wide JIT dump file. Perf only accepts a unique file per process, in the injection step.
34static JITDUMP_FILE: Mutex<Option<JitDumpFile>> = Mutex::new(None);
35
36impl JitDumpAgent {
37    /// Intialize a JitDumpAgent and write out the header.
38    pub fn new() -> Result<Self> {
39        let mut jitdump_file = JITDUMP_FILE.lock().unwrap();
40
41        if jitdump_file.is_none() {
42            let filename = format!("./jit-{}.dump", process::id());
43            let e_machine = match target_lexicon::HOST.architecture {
44                Architecture::X86_64 => elf::EM_X86_64 as u32,
45                Architecture::X86_32(_) => elf::EM_386 as u32,
46                Architecture::Arm(_) => elf::EM_ARM as u32,
47                Architecture::Aarch64(_) => elf::EM_AARCH64 as u32,
48                Architecture::S390x => elf::EM_S390 as u32,
49                _ => unimplemented!("unrecognized architecture"),
50            };
51            *jitdump_file = Some(JitDumpFile::new(filename, e_machine)?);
52        }
53
54        Ok(JitDumpAgent { dump_funcs: true })
55    }
56}
57
58impl ProfilingAgent for JitDumpAgent {
59    /// Sent when a method is compiled and loaded into memory by the VM.
60    fn module_load(&self, module: &CompiledModule, dbg_image: Option<&[u8]>) {
61        let mut jitdump_file = JITDUMP_FILE.lock().unwrap();
62        let jitdump_file = jitdump_file.as_mut().unwrap();
63
64        let pid = process::id();
65        let tid = pid; // ThreadId does appear to track underlying thread. Using PID.
66
67        for (idx, func) in module.finished_functions() {
68            let addr = func.as_ptr();
69            let len = func.len();
70            if let Some(img) = &dbg_image {
71                if let Err(err) =
72                    self.dump_from_debug_image(jitdump_file, img, "wasm", addr, len, pid, tid)
73                {
74                    println!(
75                        "Jitdump: module_load failed dumping from debug image: {:?}\n",
76                        err
77                    );
78                }
79            } else {
80                let timestamp = jitdump_file.get_time_stamp();
81                let name = super::debug_name(module, idx);
82                if let Err(err) =
83                    jitdump_file.dump_code_load_record(&name, addr, len, timestamp, pid, tid)
84                {
85                    println!("Jitdump: write_code_load_failed_record failed: {:?}\n", err);
86                }
87            }
88        }
89
90        // Note: these are the trampolines into exported functions.
91        for (idx, func, len) in module.trampolines() {
92            let (addr, len) = (func as usize as *const u8, len);
93            let timestamp = jitdump_file.get_time_stamp();
94            let name = format!("wasm::trampoline[{}]", idx.index());
95            if let Err(err) =
96                jitdump_file.dump_code_load_record(&name, addr, len, timestamp, pid, tid)
97            {
98                println!("Jitdump: write_code_load_failed_record failed: {:?}\n", err);
99            }
100        }
101    }
102
103    fn load_single_trampoline(&self, name: &str, addr: *const u8, size: usize, pid: u32, tid: u32) {
104        let mut jitdump_file = JITDUMP_FILE.lock().unwrap();
105        let jitdump_file = jitdump_file.as_mut().unwrap();
106
107        let timestamp = jitdump_file.get_time_stamp();
108        if let Err(err) = jitdump_file.dump_code_load_record(&name, addr, size, timestamp, pid, tid)
109        {
110            println!("Jitdump: write_code_load_failed_record failed: {:?}\n", err);
111        }
112    }
113}
114
115impl JitDumpAgent {
116    /// Attempts to dump debuginfo data structures, adding method and line level
117    /// for the jitted function.
118    pub fn dump_from_debug_image(
119        &self,
120        jitdump_file: &mut JitDumpFile,
121        dbg_image: &[u8],
122        module_name: &str,
123        addr: *const u8,
124        len: usize,
125        pid: u32,
126        tid: u32,
127    ) -> Result<()> {
128        let file = object::File::parse(dbg_image).unwrap();
129        let endian = if file.is_little_endian() {
130            gimli::RunTimeEndian::Little
131        } else {
132            gimli::RunTimeEndian::Big
133        };
134
135        let load_section = |id: gimli::SectionId| -> Result<borrow::Cow<[u8]>> {
136            if let Some(section) = file.section_by_name(id.name()) {
137                Ok(section.data()?.into())
138            } else {
139                Ok((&[] as &[u8]).into())
140            }
141        };
142
143        let dwarf_cow = gimli::Dwarf::load(&load_section)?;
144        let borrow_section: &dyn for<'a> Fn(
145            &'a borrow::Cow<[u8]>,
146        )
147            -> gimli::EndianSlice<'a, gimli::RunTimeEndian> =
148            &|section| gimli::EndianSlice::new(&*section, endian);
149
150        let dwarf = dwarf_cow.borrow(&borrow_section);
151
152        let mut iter = dwarf.units();
153        while let Some(header) = iter.next()? {
154            let unit = match dwarf.unit(header) {
155                Ok(unit) => unit,
156                Err(_err) => {
157                    return Ok(());
158                }
159            };
160            self.dump_entries(jitdump_file, unit, &dwarf, module_name, addr, len, pid, tid)?;
161            // TODO: Temp exit to avoid duplicate addresses being covered by only
162            // processing the top unit
163            break;
164        }
165        if !self.dump_funcs {
166            let timestamp = jitdump_file.get_time_stamp();
167            if let Err(err) =
168                jitdump_file.dump_code_load_record(module_name, addr, len, timestamp, pid, tid)
169            {
170                println!("Jitdump: write_code_load_failed_record failed: {:?}\n", err);
171            }
172        }
173        Ok(())
174    }
175
176    fn dump_entries<R: Reader>(
177        &self,
178        jitdump_file: &mut JitDumpFile,
179        unit: gimli::Unit<R>,
180        dwarf: &gimli::Dwarf<R>,
181        module_name: &str,
182        addr: *const u8,
183        len: usize,
184        pid: u32,
185        tid: u32,
186    ) -> Result<()> {
187        let mut depth = 0;
188        let mut entries = unit.entries();
189        while let Some((delta_depth, entry)) = entries.next_dfs()? {
190            if self.dump_funcs {
191                let record_header = RecordHeader {
192                    id: RecordId::JitCodeLoad as u32,
193                    record_size: 0,
194                    timestamp: 0,
195                };
196
197                let mut clr = CodeLoadRecord {
198                    header: record_header,
199                    pid,
200                    tid,
201                    virtual_address: 0,
202                    address: 0,
203                    size: 0,
204                    index: 0,
205                };
206                let mut clr_name: String = String::from(module_name);
207                let mut get_debug_entry = false;
208                depth += delta_depth;
209                assert!(depth >= 0);
210
211                if entry.tag() == gimli::constants::DW_TAG_subprogram {
212                    get_debug_entry = true;
213
214                    let mut attrs = entry.attrs();
215                    while let Some(attr) = attrs.next()? {
216                        if let Some(n) = attr.name().static_string() {
217                            if n == "DW_AT_low_pc" {
218                                clr.address = match attr.value() {
219                                    gimli::AttributeValue::Addr(address) => address,
220                                    _ => 0,
221                                };
222                                clr.virtual_address = clr.address;
223                            } else if n == "DW_AT_high_pc" {
224                                clr.size = match attr.value() {
225                                    gimli::AttributeValue::Udata(data) => data,
226                                    _ => 0,
227                                };
228                            } else if n == "DW_AT_name" {
229                                clr_name = match attr.value() {
230                                    gimli::AttributeValue::DebugStrRef(offset) => {
231                                        if let Ok(s) = dwarf.debug_str.get_str(offset) {
232                                            clr_name.push_str("::");
233                                            clr_name.push_str(&s.to_string_lossy()?);
234                                            clr_name
235                                        } else {
236                                            clr_name.push_str("::");
237                                            clr_name.push_str("?");
238                                            clr_name
239                                        }
240                                    }
241                                    _ => {
242                                        clr_name.push_str("??");
243                                        clr_name
244                                    }
245                                };
246                            }
247                        }
248                    }
249                }
250                if get_debug_entry {
251                    //  TODO: Temp check to make sure well only formed data is processed.
252                    if clr.address == 0 {
253                        continue;
254                    }
255                    //  TODO: Temp check to make sure well only formed data is processed.
256                    if clr_name == "?" {
257                        continue;
258                    }
259                    if clr.address == 0 || clr.size == 0 {
260                        clr.address = addr as u64;
261                        clr.virtual_address = addr as u64;
262                        clr.size = len as u64;
263                    }
264                    clr.header.record_size = mem::size_of::<CodeLoadRecord>() as u32
265                        + (clr_name.len() + 1) as u32
266                        + clr.size as u32;
267                    clr.index = jitdump_file.next_code_index();
268                    self.dump_debug_info(jitdump_file, &unit, &dwarf, clr.address, clr.size, None)?;
269
270                    clr.header.timestamp = jitdump_file.get_time_stamp();
271
272                    unsafe {
273                        let code_buffer: &[u8] =
274                            std::slice::from_raw_parts(clr.address as *const u8, clr.size as usize);
275                        let _ = jitdump_file.write_code_load_record(&clr_name, clr, code_buffer);
276                    }
277                }
278            } else {
279                let mut func_name: String = String::from("?");
280                let mut func_addr = 0;
281                let mut func_size = 0;
282
283                let mut get_debug_entry = false;
284                depth += delta_depth;
285                assert!(depth >= 0);
286                if entry.tag() == gimli::constants::DW_TAG_subprogram {
287                    get_debug_entry = true;
288
289                    let mut attrs = entry.attrs();
290                    while let Some(attr) = attrs.next()? {
291                        if let Some(n) = attr.name().static_string() {
292                            if n == "DW_AT_low_pc" {
293                                func_addr = match attr.value() {
294                                    gimli::AttributeValue::Addr(address) => address,
295                                    _ => 0,
296                                };
297                            } else if n == "DW_AT_high_pc" {
298                                func_size = match attr.value() {
299                                    gimli::AttributeValue::Udata(data) => data,
300                                    _ => 0,
301                                };
302                            } else if n == "DW_AT_name" {
303                                func_name = match attr.value() {
304                                    gimli::AttributeValue::DebugStrRef(offset) => {
305                                        if let Ok(s) = dwarf.debug_str.get_str(offset) {
306                                            func_name.clear();
307                                            func_name.push_str(&s.to_string_lossy()?);
308                                            func_name
309                                        } else {
310                                            func_name.push_str("?");
311                                            func_name
312                                        }
313                                    }
314                                    _ => {
315                                        func_name.push_str("??");
316                                        func_name
317                                    }
318                                };
319                            }
320                        }
321                    }
322                }
323                if get_debug_entry {
324                    //  TODO: Temp check to make sure well only formed data is processed.
325                    if func_addr == 0 {
326                        continue;
327                    }
328                    //  TODO: Temp check to make sure well only formed data is processed.
329                    if func_name == "?" {
330                        continue;
331                    }
332                    self.dump_debug_info(
333                        jitdump_file,
334                        &unit,
335                        &dwarf,
336                        func_addr,
337                        func_size,
338                        Some(func_name.as_str()),
339                    )?;
340                }
341            }
342        }
343        Ok(())
344    }
345
346    fn dump_debug_info<R: Reader>(
347        &self,
348        jitdump_file: &mut JitDumpFile,
349        unit: &gimli::Unit<R>,
350        dwarf: &gimli::Dwarf<R>,
351        address: u64,
352        size: u64,
353        file_suffix: Option<&str>,
354    ) -> Result<()> {
355        let timestamp = jitdump_file.get_time_stamp();
356        if let Some(program) = unit.line_program.clone() {
357            let mut debug_info_record = DebugInfoRecord {
358                header: RecordHeader {
359                    id: RecordId::JitCodeDebugInfo as u32,
360                    record_size: 0,
361                    timestamp,
362                },
363                address,
364                count: 0,
365            };
366
367            let mut debug_entries = Vec::new();
368            let mut debug_entries_total_filenames_len = 0;
369            let mut rows = program.rows();
370            while let Some((header, row)) = rows.next_row()? {
371                let row_file_index = row.file_index() - 1;
372                let myfile = dwarf
373                    .attr_string(
374                        &unit,
375                        header.file_names()[row_file_index as usize].path_name(),
376                    )
377                    .unwrap();
378                let filename = myfile.to_string_lossy()?;
379                let line = row.line().map(|nonzero| nonzero.get()).unwrap_or(0);
380                let column = match row.column() {
381                    gimli::ColumnType::Column(column) => column.get(),
382                    gimli::ColumnType::LeftEdge => 0,
383                };
384
385                if (row.address() < address) || (row.address() > (address + size)) {
386                    continue;
387                }
388                let mut debug_entry = DebugEntry {
389                    address: row.address(),
390                    line: line as u32,
391                    discriminator: column as u32,
392                    filename: filename.to_string(),
393                };
394
395                if let Some(suffix) = file_suffix {
396                    debug_entry.filename.push_str("::");
397                    debug_entry.filename.push_str(suffix);
398                }
399
400                debug_entries_total_filenames_len += debug_entry.filename.len() + 1;
401                debug_entries.push(debug_entry);
402            }
403
404            debug_info_record.count = debug_entries.len() as u64;
405
406            let debug_entries_size = (debug_info_record.count
407                * (mem::size_of::<DebugEntry>() as u64 - mem::size_of::<String>() as u64))
408                + debug_entries_total_filenames_len as u64;
409            debug_info_record.header.record_size =
410                mem::size_of::<DebugInfoRecord>() as u32 + debug_entries_size as u32;
411
412            let _ = jitdump_file.write_debug_info_record(debug_info_record);
413            let _ = jitdump_file.write_debug_info_entries(debug_entries);
414        }
415        Ok(())
416    }
417}
418
419trait Reader: gimli::Reader<Offset = usize> + Send + Sync {}
420
421impl<'input, Endian> Reader for gimli::EndianSlice<'input, Endian> where
422    Endian: gimli::Endianity + Send + Sync
423{
424}
wasmtime_jit/profiling/jitdump_linux.rs

wasmtime_jit/profiling/
jitdump_linux.rs
