diff options
Diffstat (limited to 'yjit/src')
-rw-r--r-- | yjit/src/codegen.rs | 3 | ||||
-rw-r--r-- | yjit/src/core.rs | 2 | ||||
-rw-r--r-- | yjit/src/cruby.rs | 20 | ||||
-rw-r--r-- | yjit/src/lib.rs | 1 | ||||
-rw-r--r-- | yjit/src/log.rs | 179 | ||||
-rw-r--r-- | yjit/src/options.rs | 44 | ||||
-rw-r--r-- | yjit/src/yjit.rs | 16 |
7 files changed, 262 insertions, 3 deletions
diff --git a/yjit/src/codegen.rs b/yjit/src/codegen.rs index 7e69ba32fa..82ec10b074 100644 --- a/yjit/src/codegen.rs +++ b/yjit/src/codegen.rs @@ -458,6 +458,7 @@ macro_rules! perf_call { } use crate::codegen::JCCKinds::*; +use crate::log::Log; #[allow(non_camel_case_types, unused)] pub enum JCCKinds { @@ -1223,6 +1224,8 @@ pub fn gen_single_block( asm_comment!(asm, "reg_mapping: {:?}", asm.ctx.get_reg_mapping()); } + Log::add_block_with_chain_depth(blockid, asm.ctx.get_chain_depth()); + // Mark the start of an ISEQ for --yjit-perf jit_perf_symbol_push!(jit, &mut asm, &get_iseq_name(iseq), PerfMap::ISEQ); diff --git a/yjit/src/core.rs b/yjit/src/core.rs index 32bce76a01..ef91638ca6 100644 --- a/yjit/src/core.rs +++ b/yjit/src/core.rs @@ -1763,7 +1763,7 @@ pub struct IseqPayload { // Basic block versions pub version_map: VersionMap, - // Indexes of code pages used by this this ISEQ + // Indexes of code pages used by this ISEQ pub pages: HashSet<usize>, // List of ISEQ entry codes diff --git a/yjit/src/cruby.rs b/yjit/src/cruby.rs index 702aaf51bc..25fabec1d0 100644 --- a/yjit/src/cruby.rs +++ b/yjit/src/cruby.rs @@ -84,6 +84,7 @@ use std::convert::From; use std::ffi::{CString, CStr}; +use std::fmt::{Debug, Formatter}; use std::os::raw::{c_char, c_int, c_uint}; use std::panic::{catch_unwind, UnwindSafe}; @@ -563,6 +564,18 @@ impl From<*const rb_callable_method_entry_t> for VALUE { } } +impl From<&str> for VALUE { + fn from(value: &str) -> Self { + rust_str_to_ruby(value) + } +} + +impl From<String> for VALUE { + fn from(value: String) -> Self { + rust_str_to_ruby(&value) + } +} + impl From<VALUE> for u64 { fn from(value: VALUE) -> Self { let VALUE(uimm) = value; @@ -594,7 +607,6 @@ impl From<VALUE> for u16 { } /// Produce a Ruby string from a Rust string slice -#[cfg(feature = "disasm")] pub fn rust_str_to_ruby(str: &str) -> VALUE { unsafe { rb_utf8_str_new(str.as_ptr() as *const _, str.len() as i64) } } @@ -625,6 +637,12 @@ pub struct SourceLocation { pub line: c_int, } +impl Debug for SourceLocation { + fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result { + f.write_fmt(format_args!("{}:{}", self.file.to_string_lossy(), self.line)) + } +} + /// Make a [SourceLocation] at the current spot. macro_rules! src_loc { () => { diff --git a/yjit/src/lib.rs b/yjit/src/lib.rs index 3f3d24be4b..1e3f31b88b 100644 --- a/yjit/src/lib.rs +++ b/yjit/src/lib.rs @@ -15,3 +15,4 @@ mod stats; mod utils; mod yjit; mod virtualmem; +mod log; diff --git a/yjit/src/log.rs b/yjit/src/log.rs new file mode 100644 index 0000000000..f2dcf519e0 --- /dev/null +++ b/yjit/src/log.rs @@ -0,0 +1,179 @@ +use crate::core::BlockId; +use crate::cruby::*; +use crate::options::*; +use crate::yjit::yjit_enabled_p; + +use std::fmt::{Display, Formatter}; +use std::os::raw::c_long; +use crate::utils::iseq_get_location; + +type Timestamp = f64; + +#[derive(Clone, Debug)] +pub struct LogEntry { + /// The time when the block was compiled. + pub timestamp: Timestamp, + + /// The log message. + pub message: String, +} + +impl Display for LogEntry { + fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result { + write!(f, "{:15.6}: {}", self.timestamp, self.message) + } +} + +pub type Log = CircularBuffer<LogEntry, 1024>; +static mut LOG: Option<Log> = None; + +impl Log { + pub fn init() { + unsafe { + LOG = Some(Log::new()); + } + } + + pub fn get_instance() -> &'static mut Log { + unsafe { + LOG.as_mut().unwrap() + } + } + + pub fn has_instance() -> bool { + unsafe { + LOG.as_mut().is_some() + } + } + + pub fn add_block_with_chain_depth(block_id: BlockId, chain_depth: u8) { + if !Self::has_instance() { + return; + } + + let print_log = get_option!(log); + let timestamp = std::time::SystemTime::now().duration_since(std::time::UNIX_EPOCH).unwrap().as_secs_f64(); + + let location = iseq_get_location(block_id.iseq, block_id.idx); + let index = block_id.idx; + let message = if chain_depth > 0 { + format!("{} (index: {}, chain_depth: {})", location, index, chain_depth) + } else { + format!("{} (index: {})", location, index) + }; + + let entry = LogEntry { + timestamp, + message + }; + + if let Some(output) = print_log { + match output { + LogOutput::Stderr => { + eprintln!("{}", entry); + } + + LogOutput::File(fd) => { + use std::os::unix::io::{FromRawFd, IntoRawFd}; + use std::io::Write; + + // Write with the fd opened during boot + let mut file = unsafe { std::fs::File::from_raw_fd(fd) }; + writeln!(file, "{}", entry).unwrap(); + file.flush().unwrap(); + file.into_raw_fd(); // keep the fd open + } + + LogOutput::MemoryOnly => () // Don't print or write anything + } + } + + Self::get_instance().push(entry); + } +} + +pub struct CircularBuffer<T, const N: usize> { + buffer: Vec<Option<T>>, + head: usize, + tail: usize, + size: usize +} + +impl<T: Clone, const N: usize> CircularBuffer<T, N> { + pub fn new() -> Self { + Self { + buffer: vec![None; N], + head: 0, + tail: 0, + size: 0 + } + } + + pub fn push(&mut self, value: T) { + self.buffer[self.head] = Some(value); + self.head = (self.head + 1) % N; + if self.size == N { + self.tail = (self.tail + 1) % N; + } else { + self.size += 1; + } + } + + pub fn pop(&mut self) -> Option<T> { + if self.size == 0 { + return None; + } + + let value = self.buffer[self.tail].take(); + self.tail = (self.tail + 1) % N; + self.size -= 1; + value + } + + pub fn len(&self) -> usize { + self.size + } +} + + +//=========================================================================== + +/// Primitive called in yjit.rb +/// Check if log generation is enabled +#[no_mangle] +pub extern "C" fn rb_yjit_log_enabled_p(_ec: EcPtr, _ruby_self: VALUE) -> VALUE { + if get_option!(log).is_some() { + return Qtrue; + } else { + return Qfalse; + } +} + +/// Primitive called in yjit.rb. +/// Export all YJIT log entries as a Ruby array. +#[no_mangle] +pub extern "C" fn rb_yjit_get_log(_ec: EcPtr, _ruby_self: VALUE) -> VALUE { + with_vm_lock(src_loc!(), || rb_yjit_get_log_array()) +} + +fn rb_yjit_get_log_array() -> VALUE { + if !yjit_enabled_p() || get_option!(log).is_none() { + return Qnil; + } + + let log = Log::get_instance(); + let array = unsafe { rb_ary_new_capa(log.len() as c_long) }; + + while log.len() > 0 { + let entry = log.pop().unwrap(); + + unsafe { + let entry_array = rb_ary_new_capa(2); + rb_ary_push(entry_array, rb_float_new(entry.timestamp)); + rb_ary_push(entry_array, entry.message.into()); + rb_ary_push(array, entry_array); + } + } + + return array; +} diff --git a/yjit/src/options.rs b/yjit/src/options.rs index c91c365738..b993b5685b 100644 --- a/yjit/src/options.rs +++ b/yjit/src/options.rs @@ -82,6 +82,9 @@ pub struct Options { /// Enable writing /tmp/perf-{pid}.map for Linux perf pub perf_map: Option<PerfMap>, + + // Where to store the log. `None` disables the log. + pub log: Option<LogOutput>, } // Initialize the options to default values @@ -103,6 +106,7 @@ pub static mut OPTIONS: Options = Options { frame_pointer: false, code_gc: false, perf_map: None, + log: None, }; /// YJIT option descriptions for `ruby --help`. @@ -113,6 +117,7 @@ pub const YJIT_OPTIONS: &'static [(&str, &str)] = &[ ("--yjit-call-threshold=num", "Number of calls to trigger JIT."), ("--yjit-cold-threshold=num", "Global calls after which ISEQs not compiled (default: 200K)."), ("--yjit-stats", "Enable collecting YJIT statistics."), + ("--yjit--log[=file|dir]", "Enable logging of YJIT's compilation activity."), ("--yjit-disable", "Disable YJIT for lazily enabling it with RubyVM::YJIT.enable."), ("--yjit-code-gc", "Run code GC when the code size reaches the limit."), ("--yjit-perf", "Enable frame pointers and perf profiling."), @@ -128,6 +133,16 @@ pub enum TraceExits { Counter(Counter), } +#[derive(Clone, Copy, PartialEq, Eq, Debug)] +pub enum LogOutput { + // Dump to the log file as events occur. + File(std::os::unix::io::RawFd), + // Keep the log in memory only + MemoryOnly, + // Dump to stderr when the process exits + Stderr +} + #[derive(Debug)] pub enum DumpDisasm { // Dump to stdout @@ -170,6 +185,7 @@ macro_rules! get_option_ref { }; } pub(crate) use get_option_ref; +use crate::log::Log; /// Expected to receive what comes after the third dash in "--yjit-*". /// Empty string means user passed only "--yjit". C code rejects when @@ -310,6 +326,34 @@ pub fn parse_option(str_ptr: *const std::os::raw::c_char) -> Option<()> { return None; } }, + ("log", _) => match opt_val { + "" => unsafe { + OPTIONS.log = Some(LogOutput::Stderr); + Log::init(); + }, + "quiet" => unsafe { + OPTIONS.log = Some(LogOutput::MemoryOnly); + Log::init(); + }, + arg_value => { + let log_file_path = if std::path::Path::new(arg_value).is_dir() { + format!("{arg_value}/yjit_{}.log", std::process::id()) + } else { + arg_value.to_string() + }; + + match File::options().create(true).write(true).truncate(true).open(&log_file_path) { + Ok(file) => { + use std::os::unix::io::IntoRawFd; + eprintln!("YJIT log: {log_file_path}"); + + unsafe { OPTIONS.log = Some(LogOutput::File(file.into_raw_fd())) } + Log::init() + } + Err(err) => panic!("Failed to create {log_file_path}: {err}"), + } + } + }, ("trace-exits", _) => unsafe { OPTIONS.gen_stats = true; OPTIONS.trace_exits = match opt_val { diff --git a/yjit/src/yjit.rs b/yjit/src/yjit.rs index c2647d55f7..a9ecc24a80 100644 --- a/yjit/src/yjit.rs +++ b/yjit/src/yjit.rs @@ -8,6 +8,7 @@ use crate::stats::incr_counter; use crate::stats::with_compile_time; use std::os::raw; +use crate::log::Log; /// Is YJIT on? The interpreter uses this variable to decide whether to trigger /// compilation. See jit_exec() and jit_compile(). @@ -167,7 +168,7 @@ pub extern "C" fn rb_yjit_code_gc(_ec: EcPtr, _ruby_self: VALUE) -> VALUE { /// Enable YJIT compilation, returning true if YJIT was previously disabled #[no_mangle] -pub extern "C" fn rb_yjit_enable(_ec: EcPtr, _ruby_self: VALUE, gen_stats: VALUE, print_stats: VALUE) -> VALUE { +pub extern "C" fn rb_yjit_enable(_ec: EcPtr, _ruby_self: VALUE, gen_stats: VALUE, print_stats: VALUE, gen_log: VALUE, print_log: VALUE) -> VALUE { with_vm_lock(src_loc!(), || { // Initialize and enable YJIT if gen_stats.test() { @@ -176,6 +177,19 @@ pub extern "C" fn rb_yjit_enable(_ec: EcPtr, _ruby_self: VALUE, gen_stats: VALUE OPTIONS.print_stats = print_stats.test(); } } + + if gen_log.test() { + unsafe { + if print_log.test() { + OPTIONS.log = Some(LogOutput::Stderr); + } else { + OPTIONS.log = Some(LogOutput::MemoryOnly); + } + + Log::init(); + } + } + yjit_init(); // Add "+YJIT" to RUBY_DESCRIPTION |