diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 067efb5..2a603d3 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -43,7 +43,7 @@ jobs: - name: Setup Ruby uses: ruby/setup-ruby@v1 with: - ruby-version: '3.2' + ruby-version: '3.4' - name: Setup Rust uses: dtolnay/rust-toolchain@stable with: @@ -75,7 +75,7 @@ jobs: - name: Setup Ruby uses: ruby/setup-ruby@v1 with: - ruby-version: '3.2' + ruby-version: '3.4' - name: Setup Rust uses: dtolnay/rust-toolchain@stable - name: Install Ruby dependencies diff --git a/flake.nix b/flake.nix index c3ba90c..c70325d 100644 --- a/flake.nix +++ b/flake.nix @@ -47,7 +47,9 @@ in { default = pkgs.mkShell { packages = with pkgs; [ - ruby + # WARNING: `3.4` needed in `./gems/codetracer-ruby-recorder/ext/native_tracer/src/lib.rs` + # for the `thread` field of `rb_internal_thread_event_data_t` + ruby_3_4 # The native extension is implemented in Rust (rust-toolchain-for system) diff --git a/gems/codetracer-ruby-recorder/ext/native_tracer/Cargo.lock b/gems/codetracer-ruby-recorder/ext/native_tracer/Cargo.lock index 3c72bb3..e0bc7ed 100644 --- a/gems/codetracer-ruby-recorder/ext/native_tracer/Cargo.lock +++ b/gems/codetracer-ruby-recorder/ext/native_tracer/Cargo.lock @@ -122,6 +122,12 @@ dependencies = [ "runtime_tracing", ] +[[package]] +name = "dyn-clone" +version = "1.0.20" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d0881ea181b1df73ff77ffaaf9c7544ecc11e82fba9b5f27b262a3c73a332555" + [[package]] name = "either" version = "1.15.0" @@ -353,9 +359,9 @@ checksum = "2b15c43186be67a4fd63bee50d0303afffcef381492ebe2c5d87f324e1b8815c" [[package]] name = "runtime_tracing" -version = "0.14.0" +version = "0.15.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "bb39bbb7e2fe3f83c9020a2f871e7affd293e1ef5cc2f1c137012d9931611db6" +checksum = "16c8697e99c07e9c5a580ab906a19b81b814f4cf1573da0657dd387a49d49b08" dependencies = [ "base64", "capnp", @@ -364,6 +370,8 @@ dependencies = [ "fscommon", "num-derive", "num-traits", + "ruzstd", + "schemars", "serde", "serde_json", "serde_repr", @@ -376,12 +384,45 @@ version = "1.1.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "08d43f7aa6b08d49f382cde6a7982047c3426db949b1424bc4b7ec9ae12c6ce2" +[[package]] +name = "ruzstd" +version = "0.8.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3640bec8aad418d7d03c72ea2de10d5c646a598f9883c7babc160d91e3c1b26c" +dependencies = [ + "twox-hash", +] + [[package]] name = "ryu" version = "1.0.20" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "28d3b2b1366ec20994f1fd18c3c594f05c5dd4bc44d8bb0c1c632c8d6829481f" +[[package]] +name = "schemars" +version = "0.8.22" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3fbf2ae1b8bc8e02df939598064d22402220cd5bbcca1c76f7d6a310974d5615" +dependencies = [ + "dyn-clone", + "schemars_derive", + "serde", + "serde_json", +] + +[[package]] +name = "schemars_derive" +version = "0.8.22" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "32e265784ad618884abaea0600a9adf15393368d840e0222d101a072f3f7534d" +dependencies = [ + "proc-macro2", + "quote", + "serde_derive_internals", + "syn", +] + [[package]] name = "serde" version = "1.0.219" @@ -402,6 +443,17 @@ dependencies = [ "syn", ] +[[package]] +name = "serde_derive_internals" +version = "0.29.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "18d26a20a969b9e3fdf2fc2d9f21eda6c40e2de84c9408bb5d3b05d499aae711" +dependencies = [ + "proc-macro2", + "quote", + "syn", +] + [[package]] name = "serde_json" version = "1.0.140" @@ -448,6 +500,12 @@ dependencies = [ "unicode-ident", ] +[[package]] +name = "twox-hash" +version = "2.1.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9ea3136b675547379c4bd395ca6b938e5ad3c3d20fad76e7fe85f9e0d011419c" + [[package]] name = "unicode-ident" version = "1.0.18" @@ -538,9 +596,9 @@ dependencies = [ [[package]] name = "zeekstd" -version = "0.5.0" +version = "0.6.1" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "48ee50810d0fa308a167f17f08243378b36f0d9fd5e43e95c4943a1e51b7b8a5" +checksum = "eb8d93ff6453f9e75288f804307c0d939917b482e1948281f8b0514decf77437" dependencies = [ "zstd-safe", ] diff --git a/gems/codetracer-ruby-recorder/ext/native_tracer/Cargo.toml b/gems/codetracer-ruby-recorder/ext/native_tracer/Cargo.toml index 551098c..7d5c971 100644 --- a/gems/codetracer-ruby-recorder/ext/native_tracer/Cargo.toml +++ b/gems/codetracer-ruby-recorder/ext/native_tracer/Cargo.toml @@ -11,7 +11,7 @@ crate-type = ["cdylib"] [dependencies] rb-sys = "0.9" -runtime_tracing = "0.14.0" +runtime_tracing = "0.15.0" [build-dependencies] rb-sys-env = "0.2" diff --git a/gems/codetracer-ruby-recorder/ext/native_tracer/src/lib.rs b/gems/codetracer-ruby-recorder/ext/native_tracer/src/lib.rs index 3e147b4..674e3f3 100644 --- a/gems/codetracer-ruby-recorder/ext/native_tracer/src/lib.rs +++ b/gems/codetracer-ruby-recorder/ext/native_tracer/src/lib.rs @@ -1,5 +1,6 @@ #![allow(clippy::missing_safety_doc)] +use std::sync::Mutex; use std::{ collections::HashMap, ffi::CStr, @@ -11,22 +12,26 @@ use std::{ }; use rb_sys::{ - rb_add_event_hook2, rb_cObject, rb_cRange, rb_cRegexp, rb_cStruct, rb_cTime, + rb_add_event_hook2, rb_cObject, rb_cRange, rb_cRegexp, rb_cStruct, rb_cThread, rb_cTime, rb_check_typeddata, rb_const_defined, rb_const_get, rb_data_type_struct__bindgen_ty_1, rb_data_type_t, rb_data_typed_object_wrap, rb_define_alloc_func, rb_define_class, - rb_define_method, rb_eIOError, rb_event_flag_t, rb_event_hook_flag_t, rb_event_hook_func_t, - rb_funcall, rb_id2name, rb_id2sym, rb_intern, rb_method_boundp, rb_num2dbl, rb_num2long, - rb_obj_classname, rb_obj_is_kind_of, rb_protect, rb_raise, rb_remove_event_hook_with_data, - rb_set_errinfo, rb_sym2id, rb_trace_arg_t, rb_tracearg_binding, rb_tracearg_callee_id, - rb_tracearg_event_flag, rb_tracearg_lineno, rb_tracearg_path, rb_tracearg_raised_exception, - rb_tracearg_return_value, rb_tracearg_self, Qfalse, Qnil, Qtrue, ID, NIL_P, RARRAY_CONST_PTR, - RARRAY_LEN, RB_FLOAT_TYPE_P, RB_INTEGER_TYPE_P, RB_SYMBOL_P, RB_TYPE_P, RSTRING_LEN, - RSTRING_PTR, RUBY_EVENT_CALL, RUBY_EVENT_LINE, RUBY_EVENT_RAISE, RUBY_EVENT_RETURN, VALUE, + rb_define_method, rb_eIOError, rb_eval_string, rb_event_flag_t, rb_event_hook_flag_t, + rb_event_hook_func_t, rb_funcall, rb_id2name, rb_id2sym, rb_intern, + rb_internal_thread_add_event_hook, rb_internal_thread_event_data_t, rb_method_boundp, + rb_num2dbl, rb_num2long, rb_obj_classname, rb_obj_is_kind_of, rb_protect, rb_raise, + rb_remove_event_hook_with_data, rb_set_errinfo, rb_sym2id, rb_trace_arg_t, rb_tracearg_binding, + rb_tracearg_callee_id, rb_tracearg_event_flag, rb_tracearg_lineno, rb_tracearg_path, + rb_tracearg_raised_exception, rb_tracearg_return_value, rb_tracearg_self, Qfalse, Qnil, Qtrue, + ID, NIL_P, RARRAY_CONST_PTR, RARRAY_LEN, RB_FLOAT_TYPE_P, RB_INTEGER_TYPE_P, RB_SYMBOL_P, + RB_TYPE_P, RSTRING_LEN, RSTRING_PTR, RUBY_EVENT_CALL, RUBY_EVENT_LINE, RUBY_EVENT_RAISE, + RUBY_EVENT_RETURN, RUBY_INTERNAL_THREAD_EVENT_EXITED, RUBY_INTERNAL_THREAD_EVENT_READY, + RUBY_INTERNAL_THREAD_EVENT_RESUMED, RUBY_INTERNAL_THREAD_EVENT_STARTED, + RUBY_INTERNAL_THREAD_EVENT_SUSPENDED, VALUE, }; use runtime_tracing::{ create_trace_writer, CallRecord, EventLogKind, FieldTypeRecord, FullValueRecord, Line, - TraceEventsFileFormat, TraceLowLevelEvent, TraceWriter, TypeKind, TypeRecord, TypeSpecificInfo, - ValueRecord, + ThreadId, TraceEventsFileFormat, TraceLowLevelEvent, TraceWriter, TypeKind, TypeRecord, + TypeSpecificInfo, ValueRecord, }; struct InternedSymbols { @@ -79,9 +84,11 @@ impl InternedSymbols { } } -struct Recorder { - tracer: Box, +struct RecorderData { active: bool, + in_event_hook: bool, + thread_event_hook_installed: bool, + last_thread_id: Option, id: InternedSymbols, set_class: VALUE, open_struct_class: VALUE, @@ -94,6 +101,11 @@ struct Recorder { error_type_id: runtime_tracing::TypeId, } +struct Recorder { + tracer: Mutex>, + data: RecorderData, +} + fn should_ignore_path(path: &str) -> bool { const PATTERNS: [&str; 5] = [ "codetracer_ruby_recorder.rb", @@ -129,7 +141,8 @@ fn value_type_id(val: &ValueRecord) -> runtime_tracing::TypeId { } unsafe fn struct_value + ToString>( - recorder: &mut Recorder, + recorder: &mut RecorderData, + tracer: &mut dyn TraceWriter, class_name: &str, field_names: &[T], field_values: &[VALUE], @@ -137,7 +150,7 @@ unsafe fn struct_value + ToString>( ) -> ValueRecord { let mut vals = Vec::with_capacity(field_values.len()); for &v in field_values { - vals.push(to_value(recorder, v, depth - 1)); + vals.push(to_value(recorder, tracer, v, depth - 1)); } let version_entry = recorder @@ -160,7 +173,7 @@ unsafe fn struct_value + ToString>( fields: field_types, }, }; - let type_id = TraceWriter::ensure_raw_type_id(&mut *recorder.tracer, typ); + let type_id = TraceWriter::ensure_raw_type_id(tracer, typ); ValueRecord::Struct { field_values: vals, @@ -202,18 +215,27 @@ unsafe fn get_recorder(obj: VALUE) -> *mut Recorder { unsafe extern "C" fn ruby_recorder_alloc(klass: VALUE) -> VALUE { let recorder = Box::new(Recorder { - tracer: create_trace_writer("ruby", &vec![], TraceEventsFileFormat::Binary), - active: false, - id: InternedSymbols::new(), - set_class: Qnil.into(), - open_struct_class: Qnil.into(), - struct_type_versions: HashMap::new(), - int_type_id: runtime_tracing::TypeId::default(), - float_type_id: runtime_tracing::TypeId::default(), - bool_type_id: runtime_tracing::TypeId::default(), - string_type_id: runtime_tracing::TypeId::default(), - symbol_type_id: runtime_tracing::TypeId::default(), - error_type_id: runtime_tracing::TypeId::default(), + tracer: Mutex::new(create_trace_writer( + "ruby", + &vec![], + TraceEventsFileFormat::Binary, + )), + data: RecorderData { + active: false, + in_event_hook: false, + thread_event_hook_installed: false, + last_thread_id: None, + id: InternedSymbols::new(), + set_class: Qnil.into(), + open_struct_class: Qnil.into(), + struct_type_versions: HashMap::new(), + int_type_id: runtime_tracing::TypeId::default(), + float_type_id: runtime_tracing::TypeId::default(), + bool_type_id: runtime_tracing::TypeId::default(), + string_type_id: runtime_tracing::TypeId::default(), + symbol_type_id: runtime_tracing::TypeId::default(), + error_type_id: runtime_tracing::TypeId::default(), + }, }); let ty = std::ptr::addr_of!(RECORDER_TYPE) as *const rb_data_type_t; rb_data_typed_object_wrap(klass, Box::into_raw(recorder) as *mut c_void, ty) @@ -221,7 +243,12 @@ unsafe extern "C" fn ruby_recorder_alloc(klass: VALUE) -> VALUE { unsafe extern "C" fn enable_tracing(self_val: VALUE) -> VALUE { let recorder = &mut *get_recorder(self_val); - if !recorder.active { + if !recorder.data.active { + if !recorder.data.thread_event_hook_installed { + thread_register_callback(recorder); + recorder.data.thread_event_hook_installed = true; + } + let raw_cb: unsafe extern "C" fn(VALUE, *mut rb_trace_arg_t) = event_hook_raw; let func: rb_event_hook_func_t = Some(transmute(raw_cb)); rb_add_event_hook2( @@ -230,18 +257,18 @@ unsafe extern "C" fn enable_tracing(self_val: VALUE) -> VALUE { self_val, rb_event_hook_flag_t::RUBY_EVENT_HOOK_FLAG_RAW_ARG, ); - recorder.active = true; + recorder.data.active = true; } Qnil.into() } unsafe extern "C" fn disable_tracing(self_val: VALUE) -> VALUE { let recorder = &mut *get_recorder(self_val); - if recorder.active { + if recorder.data.active { let raw_cb: unsafe extern "C" fn(VALUE, *mut rb_trace_arg_t) = event_hook_raw; let func: rb_event_hook_func_t = Some(transmute(raw_cb)); rb_remove_event_hook_with_data(func, self_val); - recorder.active = false; + recorder.data.active = false; } Qnil.into() } @@ -308,7 +335,7 @@ unsafe extern "C" fn call_to_s(arg: VALUE) -> VALUE { rb_funcall(data.0, data.1, 0) } -unsafe fn value_to_string_exception_safe(recorder: &Recorder, val: VALUE) -> String { +unsafe fn value_to_string_exception_safe(recorder: &RecorderData, val: VALUE) -> String { if RB_TYPE_P(val, rb_sys::ruby_value_type::RUBY_T_STRING) { rstring_lossy(val) } else { @@ -324,7 +351,12 @@ unsafe fn value_to_string_exception_safe(recorder: &Recorder, val: VALUE) -> Str } } -unsafe fn to_value(recorder: &mut Recorder, val: VALUE, depth: usize) -> ValueRecord { +unsafe fn to_value( + recorder: &mut RecorderData, + tracer: &mut dyn TraceWriter, + val: VALUE, + depth: usize, +) -> ValueRecord { if depth == 0 { return ValueRecord::None { type_id: recorder.error_type_id, @@ -351,7 +383,7 @@ unsafe fn to_value(recorder: &mut Recorder, val: VALUE, depth: usize) -> ValueRe if RB_FLOAT_TYPE_P(val) { let f = rb_num2dbl(val); let type_id = if recorder.float_type_id == runtime_tracing::NONE_TYPE_ID { - let id = TraceWriter::ensure_type_id(&mut *recorder.tracer, TypeKind::Float, "Float"); + let id = TraceWriter::ensure_type_id(tracer, TypeKind::Float, "Float"); recorder.float_type_id = id; id } else { @@ -377,9 +409,9 @@ unsafe fn to_value(recorder: &mut Recorder, val: VALUE, depth: usize) -> ValueRe let ptr = RARRAY_CONST_PTR(val); for i in 0..len { let elem = *ptr.add(i); - elements.push(to_value(recorder, elem, depth - 1)); + elements.push(to_value(recorder, tracer, elem, depth - 1)); } - let type_id = TraceWriter::ensure_type_id(&mut *recorder.tracer, TypeKind::Seq, "Array"); + let type_id = TraceWriter::ensure_type_id(tracer, TypeKind::Seq, "Array"); return ValueRecord::Sequence { elements, is_slice: false, @@ -401,24 +433,29 @@ unsafe fn to_value(recorder: &mut Recorder, val: VALUE, depth: usize) -> ValueRe let val_elem = *pair_ptr.add(1); elements.push(struct_value( recorder, + tracer, "Pair", &["k", "v"], &[key, val_elem], depth, )); } - let type_id = TraceWriter::ensure_type_id(&mut *recorder.tracer, TypeKind::Seq, "Hash"); + let type_id = TraceWriter::ensure_type_id(tracer, TypeKind::Seq, "Hash"); return ValueRecord::Sequence { elements, is_slice: false, type_id, }; } + if rb_obj_is_kind_of(val, rb_cThread) != 0 { + return struct_value(recorder, tracer, "Thread", &[] as &[&str], &[], depth); + } if rb_obj_is_kind_of(val, rb_cRange) != 0 { let begin_val = rb_funcall(val, recorder.id.begin, 0); let end_val = rb_funcall(val, recorder.id.end, 0); return struct_value( recorder, + tracer, "Range", &["begin", "end"], &[begin_val, end_val], @@ -438,9 +475,9 @@ unsafe fn to_value(recorder: &mut Recorder, val: VALUE, depth: usize) -> ValueRe let mut elements = Vec::with_capacity(len); for i in 0..len { let elem = *ptr.add(i); - elements.push(to_value(recorder, elem, depth - 1)); + elements.push(to_value(recorder, tracer, elem, depth - 1)); } - let type_id = TraceWriter::ensure_type_id(&mut *recorder.tracer, TypeKind::Seq, "Set"); + let type_id = TraceWriter::ensure_type_id(tracer, TypeKind::Seq, "Set"); return ValueRecord::Sequence { elements, is_slice: false, @@ -451,13 +488,21 @@ unsafe fn to_value(recorder: &mut Recorder, val: VALUE, depth: usize) -> ValueRe if rb_obj_is_kind_of(val, rb_cTime) != 0 { let sec = rb_funcall(val, recorder.id.to_i, 0); let nsec = rb_funcall(val, recorder.id.nsec, 0); - return struct_value(recorder, "Time", &["sec", "nsec"], &[sec, nsec], depth); + return struct_value( + recorder, + tracer, + "Time", + &["sec", "nsec"], + &[sec, nsec], + depth, + ); } if rb_obj_is_kind_of(val, rb_cRegexp) != 0 { let src = rb_funcall(val, recorder.id.source, 0); let opts = rb_funcall(val, recorder.id.options, 0); return struct_value( recorder, + tracer, "Regexp", &["source", "options"], &[src, opts], @@ -473,8 +518,7 @@ unsafe fn to_value(recorder: &mut Recorder, val: VALUE, depth: usize) -> ValueRe || !RB_TYPE_P(values, rb_sys::ruby_value_type::RUBY_T_ARRAY) { let text = value_to_string_exception_safe(recorder, val); - let type_id = - TraceWriter::ensure_type_id(&mut *recorder.tracer, TypeKind::Raw, &class_name); + let type_id = TraceWriter::ensure_type_id(tracer, TypeKind::Raw, &class_name); return ValueRecord::Raw { r: text, type_id }; } let len = RARRAY_LEN(values) as usize; @@ -487,7 +531,7 @@ unsafe fn to_value(recorder: &mut Recorder, val: VALUE, depth: usize) -> ValueRe names.push(cstr_to_string(rb_id2name(rb_sym2id(sym))).unwrap_or("?".to_string())); vals.push(*val_ptr.add(i)); } - return struct_value(recorder, &class_name, &names, &vals, depth); + return struct_value(recorder, tracer, &class_name, &names, &vals, depth); } if NIL_P(recorder.open_struct_class) { if rb_const_defined(rb_cObject, recorder.id.open_struct_const) != 0 { @@ -497,15 +541,14 @@ unsafe fn to_value(recorder: &mut Recorder, val: VALUE, depth: usize) -> ValueRe if !NIL_P(recorder.open_struct_class) && rb_obj_is_kind_of(val, recorder.open_struct_class) != 0 { let h = rb_funcall(val, recorder.id.to_h, 0); - return to_value(recorder, h, depth - 1); + return to_value(recorder, tracer, h, depth - 1); } let class_name = cstr_to_string(rb_obj_classname(val)).unwrap_or_else(|| "Object".to_string()); // generic object let ivars = rb_funcall(val, recorder.id.instance_variables, 0); if !RB_TYPE_P(ivars, rb_sys::ruby_value_type::RUBY_T_ARRAY) { let text = value_to_string_exception_safe(recorder, val); - let type_id = - TraceWriter::ensure_type_id(&mut *recorder.tracer, TypeKind::Raw, &class_name); + let type_id = TraceWriter::ensure_type_id(tracer, TypeKind::Raw, &class_name); return ValueRecord::Raw { r: text, type_id }; } let len = RARRAY_LEN(ivars) as usize; @@ -519,14 +562,18 @@ unsafe fn to_value(recorder: &mut Recorder, val: VALUE, depth: usize) -> ValueRe vals.push(value); } if !names.is_empty() { - return struct_value(recorder, &class_name, &names, &vals, depth); + return struct_value(recorder, tracer, &class_name, &names, &vals, depth); } let text = value_to_string_exception_safe(recorder, val); - let type_id = TraceWriter::ensure_type_id(&mut *recorder.tracer, TypeKind::Raw, &class_name); + let type_id = TraceWriter::ensure_type_id(tracer, TypeKind::Raw, &class_name); ValueRecord::Raw { r: text, type_id } } -unsafe fn record_variables(recorder: &mut Recorder, binding: VALUE) { +unsafe fn record_variables( + recorder: &mut RecorderData, + tracer: &mut dyn TraceWriter, + binding: VALUE, +) { let vars = rb_funcall(binding, recorder.id.local_variables, 0); if !RB_TYPE_P(vars, rb_sys::ruby_value_type::RUBY_T_ARRAY) { return; @@ -537,13 +584,14 @@ unsafe fn record_variables(recorder: &mut Recorder, binding: VALUE) { let sym = *ptr.add(i); let name = cstr_to_string(rb_id2name(rb_sym2id(sym))).unwrap_or_default(); let value = rb_funcall(binding, recorder.id.local_variable_get, 1, sym); - let val_rec = to_value(recorder, value, 10); - TraceWriter::register_variable_with_full_value(&mut *recorder.tracer, &name, val_rec); + let val_rec = to_value(recorder, tracer, value, 10); + TraceWriter::register_variable_with_full_value(tracer, &name, val_rec); } } unsafe fn collect_parameter_values( - recorder: &mut Recorder, + recorder: &mut RecorderData, + tracer: &mut dyn TraceWriter, binding: VALUE, defined_class: VALUE, mid: ID, @@ -572,7 +620,7 @@ unsafe fn collect_parameter_values( } if let Some(name) = cstr_to_string(rb_id2name(rb_sym2id(name_sym))) { let value = rb_funcall(binding, recorder.id.local_variable_get, 1, name_sym); - let val_rec = to_value(recorder, value, 10); + let val_rec = to_value(recorder, tracer, value, 10); result.push((name, val_rec)); } } @@ -580,17 +628,14 @@ unsafe fn collect_parameter_values( } unsafe fn register_parameter_values( - recorder: &mut Recorder, + recorder: &mut RecorderData, + tracer: &mut dyn TraceWriter, params: Vec<(String, ValueRecord)>, ) -> Vec { let mut result = Vec::with_capacity(params.len()); for (name, val_rec) in params { - TraceWriter::register_variable_with_full_value( - &mut *recorder.tracer, - &name, - val_rec.clone(), - ); - let var_id = TraceWriter::ensure_variable_id(&mut *recorder.tracer, &name); + TraceWriter::register_variable_with_full_value(tracer, &name, val_rec.clone()); + let var_id = TraceWriter::ensure_variable_id(tracer, &name); result.push(FullValueRecord { variable_id: var_id, value: val_rec, @@ -626,40 +671,38 @@ unsafe extern "C" fn initialize(self_val: VALUE, out_dir: VALUE, format: VALUE) Ok(path_str) => { match begin_trace(Path::new(&path_str), fmt) { Ok(t) => { - recorder.tracer = t; + recorder.tracer = Mutex::new(t); + let mut locked_tracer = recorder.tracer.lock().unwrap(); // pre-register common types to match the pure Ruby tracer - recorder.int_type_id = TraceWriter::ensure_type_id( - &mut *recorder.tracer, - TypeKind::Int, - "Integer", - ); - recorder.string_type_id = TraceWriter::ensure_type_id( - &mut *recorder.tracer, + recorder.data.int_type_id = + TraceWriter::ensure_type_id(&mut **locked_tracer, TypeKind::Int, "Integer"); + recorder.data.string_type_id = TraceWriter::ensure_type_id( + &mut **locked_tracer, TypeKind::String, "String", ); - recorder.bool_type_id = - TraceWriter::ensure_type_id(&mut *recorder.tracer, TypeKind::Bool, "Bool"); - recorder.float_type_id = runtime_tracing::NONE_TYPE_ID; - recorder.symbol_type_id = TraceWriter::ensure_type_id( - &mut *recorder.tracer, + recorder.data.bool_type_id = + TraceWriter::ensure_type_id(&mut **locked_tracer, TypeKind::Bool, "Bool"); + recorder.data.float_type_id = runtime_tracing::NONE_TYPE_ID; + recorder.data.symbol_type_id = TraceWriter::ensure_type_id( + &mut **locked_tracer, TypeKind::String, "Symbol", ); - recorder.error_type_id = TraceWriter::ensure_type_id( - &mut *recorder.tracer, + recorder.data.error_type_id = TraceWriter::ensure_type_id( + &mut **locked_tracer, TypeKind::Error, "No type", ); let path = Path::new(""); let func_id = TraceWriter::ensure_function_id( - &mut *recorder.tracer, + &mut **locked_tracer, "", path, Line(1), ); TraceWriter::add_event( - &mut *recorder.tracer, + &mut **locked_tracer, TraceLowLevelEvent::Call(CallRecord { function_id: func_id, args: vec![], @@ -694,8 +737,9 @@ unsafe extern "C" fn initialize(self_val: VALUE, out_dir: VALUE, format: VALUE) unsafe extern "C" fn flush_trace(self_val: VALUE) -> VALUE { let recorder_ptr = get_recorder(self_val); let recorder = &mut *recorder_ptr; + let mut locked_tracer = recorder.tracer.lock().unwrap(); - if let Err(e) = flush_to_dir(&mut *recorder.tracer) { + if let Err(e) = flush_to_dir(&mut **locked_tracer) { let msg = std::ffi::CString::new(e.to_string()) .unwrap_or_else(|_| std::ffi::CString::new("unknown error").unwrap()); rb_raise( @@ -715,10 +759,14 @@ unsafe extern "C" fn record_event_api( content: VALUE, ) -> VALUE { let recorder = &mut *get_recorder(self_val); + if recorder.data.in_event_hook { + return Qnil.into(); + } + let mut locked_tracer = recorder.tracer.lock().unwrap(); let path_string = rstring_checked_or_empty(path); let line_num = rb_num2long(line) as i64; - let content_str = value_to_string_exception_safe(recorder, content); - record_event(&mut *recorder.tracer, &path_string, line_num, content_str); + let content_str = value_to_string_exception_safe(&recorder.data, content); + record_event(&mut **locked_tracer, &path_string, line_num, content_str); Qnil.into() } @@ -735,24 +783,48 @@ unsafe extern "C" fn event_hook_raw(data: VALUE, arg: *mut rb_trace_arg_t) { } let recorder = &mut *get_recorder(data); - if !recorder.active { + if !recorder.data.active { return; } + if recorder.data.in_event_hook { + return; + } + recorder.data.in_event_hook = true; + + let mut locked_tracer = recorder.tracer.lock().unwrap(); + let ev: rb_event_flag_t = rb_tracearg_event_flag(arg); let path_val = rb_tracearg_path(arg); let line_val = rb_tracearg_lineno(arg); let path = rstring_checked_or_empty(path_val); let line = rb_num2long(line_val) as i64; if should_ignore_path(&path) { + recorder.data.in_event_hook = false; return; } + let thread_id: u64 = rb_eval_string(c"Thread.current".as_ptr() as *const c_char) + .try_into() + .unwrap(); + let thread_changed = if let Some(last_thread_id) = recorder.data.last_thread_id { + last_thread_id != thread_id + } else { + true + }; + if thread_changed { + TraceWriter::add_event( + &mut **locked_tracer, + TraceLowLevelEvent::ThreadSwitch(ThreadId(thread_id)), + ); + recorder.data.last_thread_id = Some(thread_id); + } + if (ev & RUBY_EVENT_LINE) != 0 { let binding = rb_tracearg_binding(arg); - TraceWriter::register_step(&mut *recorder.tracer, Path::new(&path), Line(line)); + TraceWriter::register_step(&mut **locked_tracer, Path::new(&path), Line(line)); if !NIL_P(binding) { - record_variables(recorder, binding); + record_variables(&mut recorder.data, &mut **locked_tracer, binding); } } else if (ev & RUBY_EVENT_CALL) != 0 { let binding = rb_tracearg_binding(arg); @@ -760,68 +832,122 @@ unsafe extern "C" fn event_hook_raw(data: VALUE, arg: *mut rb_trace_arg_t) { let self_val = rb_tracearg_self(arg); let mid_sym = rb_tracearg_callee_id(arg); let mid = rb_sym2id(mid_sym); - let defined_class = rb_funcall(self_val, recorder.id.class, 0); + let defined_class = rb_funcall(self_val, recorder.data.id.class, 0); let param_vals = if NIL_P(binding) { Vec::new() } else { - collect_parameter_values(recorder, binding, defined_class, mid) + collect_parameter_values( + &mut recorder.data, + &mut **locked_tracer, + binding, + defined_class, + mid, + ) }; let class_name = cstr_to_string(rb_obj_classname(self_val)).unwrap_or_else(|| "Object".to_string()); - let text = value_to_string_exception_safe(recorder, self_val); + let text = value_to_string_exception_safe(&recorder.data, self_val); let self_type = - TraceWriter::ensure_type_id(&mut *recorder.tracer, TypeKind::Raw, &class_name); + TraceWriter::ensure_type_id(&mut **locked_tracer, TypeKind::Raw, &class_name); let self_rec = ValueRecord::Raw { r: text, type_id: self_type, }; TraceWriter::register_variable_with_full_value( - &mut *recorder.tracer, + &mut **locked_tracer, "self", self_rec.clone(), ); - let mut args = vec![TraceWriter::arg(&mut *recorder.tracer, "self", self_rec)]; + let mut args = vec![TraceWriter::arg(&mut **locked_tracer, "self", self_rec)]; if !param_vals.is_empty() { - args.extend(register_parameter_values(recorder, param_vals)); + args.extend(register_parameter_values( + &mut recorder.data, + &mut **locked_tracer, + param_vals, + )); } - TraceWriter::register_step(&mut *recorder.tracer, Path::new(&path), Line(line)); + TraceWriter::register_step(&mut **locked_tracer, Path::new(&path), Line(line)); let mut name = cstr_to_string(rb_id2name(mid)).unwrap_or_default(); if class_name != "Object" { name = format!("{}#{}", class_name, name); } let fid = TraceWriter::ensure_function_id( - &mut *recorder.tracer, + &mut **locked_tracer, &name, Path::new(&path), Line(line), ); TraceWriter::add_event( - &mut *recorder.tracer, + &mut **locked_tracer, TraceLowLevelEvent::Call(CallRecord { function_id: fid, args, }), ); } else if (ev & RUBY_EVENT_RETURN) != 0 { - TraceWriter::register_step(&mut *recorder.tracer, Path::new(&path), Line(line)); + TraceWriter::register_step(&mut **locked_tracer, Path::new(&path), Line(line)); let ret = rb_tracearg_return_value(arg); - let val_rec = to_value(recorder, ret, 10); + let val_rec = to_value(&mut recorder.data, &mut **locked_tracer, ret, 10); TraceWriter::register_variable_with_full_value( - &mut *recorder.tracer, + &mut **locked_tracer, "", val_rec.clone(), ); - TraceWriter::register_return(&mut *recorder.tracer, val_rec); + TraceWriter::register_return(&mut **locked_tracer, val_rec); } else if (ev & RUBY_EVENT_RAISE) != 0 { let exc = rb_tracearg_raised_exception(arg); - let msg = value_to_string_exception_safe(recorder, exc); - TraceWriter::register_special_event(&mut *recorder.tracer, EventLogKind::Error, &msg); + let msg = value_to_string_exception_safe(&recorder.data, exc); + TraceWriter::register_special_event(&mut **locked_tracer, EventLogKind::Error, &msg); + } + recorder.data.in_event_hook = false; +} + +unsafe extern "C" fn ex_callback( + event: rb_event_flag_t, + event_data: *const rb_internal_thread_event_data_t, + user_data: *mut c_void, +) { + match event { + RUBY_INTERNAL_THREAD_EVENT_STARTED => { + let recorder = user_data as *mut Recorder; + let mut locked_tracer = (*recorder).tracer.lock().unwrap(); + let event = TraceLowLevelEvent::ThreadStart(ThreadId((*event_data).thread)); + TraceWriter::add_event(&mut **locked_tracer, event); + } + RUBY_INTERNAL_THREAD_EVENT_EXITED => { + let recorder = user_data as *mut Recorder; + let mut locked_tracer = (*recorder).tracer.lock().unwrap(); + let event = TraceLowLevelEvent::ThreadExit(ThreadId((*event_data).thread)); + TraceWriter::add_event(&mut **locked_tracer, event); + } + /*RUBY_INTERNAL_THREAD_EVENT_READY => { + println!("RUBY_INTERNAL_THREAD_EVENT_READY"); + } + RUBY_INTERNAL_THREAD_EVENT_RESUMED => { + println!("RUBY_INTERNAL_THREAD_EVENT_RESUMED"); + } + RUBY_INTERNAL_THREAD_EVENT_SUSPENDED => { + println!("RUBY_INTERNAL_THREAD_EVENT_SUSPENDED"); + }*/ + _ => {} } } +unsafe fn thread_register_callback(recorder: *mut Recorder) { + let q = rb_internal_thread_add_event_hook( + Some(ex_callback), + RUBY_INTERNAL_THREAD_EVENT_STARTED + | RUBY_INTERNAL_THREAD_EVENT_READY + | RUBY_INTERNAL_THREAD_EVENT_RESUMED + | RUBY_INTERNAL_THREAD_EVENT_SUSPENDED + | RUBY_INTERNAL_THREAD_EVENT_EXITED, + recorder as *mut c_void, + ); +} + #[no_mangle] pub extern "C" fn Init_codetracer_ruby_recorder() { unsafe { diff --git a/test/fixtures/more_types_output.txt b/test/fixtures/more_types_output.txt index 15494ed..883d9ac 100644 --- a/test/fixtures/more_types_output.txt +++ b/test/fixtures/more_types_output.txt @@ -1 +1 @@ -[1.5, {:a=>1, :b=>2}, 1..3, #, 1970-01-01 00:00:00 UTC, /ab/, #, #] +[1.5, {a: 1, b: 2}, 1..3, #, 1970-01-01 00:00:00 UTC, /ab/, #, #] diff --git a/test/fixtures/more_types_trace.json b/test/fixtures/more_types_trace.json index 9616618..2021580 100644 --- a/test/fixtures/more_types_trace.json +++ b/test/fixtures/more_types_trace.json @@ -527,7 +527,7 @@ { "Event": { "kind": 0, - "content": "1.5\n{:a=>1, :b=>2}\n1..3\n#\n1970-01-01 00:00:00 UTC\n/ab/\n#\n#\n", + "content": "1.5\n{a: 1, b: 2}\n1..3\n#\n1970-01-01 00:00:00 UTC\n/ab/\n#\n#\n", "metadata": "" } } diff --git a/test/test_kernel_patches.rb b/test/test_kernel_patches.rb index 4ad9162..65bb333 100644 --- a/test/test_kernel_patches.rb +++ b/test/test_kernel_patches.rb @@ -139,21 +139,21 @@ def test_correct_event_arguments assert_equal __FILE__, event_p[:path], "Path for p mismatch" assert_equal expected_line_p_detailed, event_p[:lineno], "Line number for p mismatch" # p calls inspect on each argument and joins with newline if multiple, but here it's one string then obj - assert_equal "\"detailed_p\"\n{:key=>\"value\", :number=>123}\n", event_p[:content], "Content for p mismatch" + assert_equal "\"detailed_p\"\n{key: \"value\", number: 123}\n", event_p[:content], "Content for p mismatch" event_puts = @tracer1.events[1] assert_equal __FILE__, event_puts[:path], "Path for puts mismatch" assert_equal expected_line_puts_detailed, event_puts[:lineno], "Line number for puts mismatch" # puts calls to_s on each argument and prints each on a new line - assert_equal "detailed_puts\n{:key=>\"value\", :number=>123}\n", event_puts[:content], "Content for puts mismatch" + assert_equal "detailed_puts\n{key: \"value\", number: 123}\n", event_puts[:content], "Content for puts mismatch" event_print = @tracer1.events[2] assert_equal __FILE__, event_print[:path], "Path for print mismatch" assert_equal expected_line_print_detailed, event_print[:lineno], "Line number for print mismatch" # print calls to_s on each argument and prints them sequentially - assert_equal "detailed_print{:key=>\"value\", :number=>123}", event_print[:content], "Content for print mismatch" + assert_equal "detailed_print{key: \"value\", number: 123}", event_print[:content], "Content for print mismatch" CodeTracer::KernelPatches.uninstall(@tracer1) end diff --git a/test/test_tracer.rb b/test/test_tracer.rb index 8df0114..990e1ac 100644 --- a/test/test_tracer.rb +++ b/test/test_tracer.rb @@ -16,6 +16,16 @@ def setup FileUtils.mkdir_p(TMP_DIR) end + def filter_trace(trace) + result = [] + trace.each {|a| + if not a.has_key?("ThreadSwitch") + result << a + end + } + result + end + def run_trace(tracer_script, program_name, *args) base = File.basename(program_name, '.rb') tracer_name = tracer_script.include?('pure') ? 'pure' : 'native' @@ -27,7 +37,7 @@ def run_trace(tracer_script, program_name, *args) stdout, stderr, status = Open3.capture3(RbConfig.ruby, tracer_script, '--out-dir', out_dir, program, *args) raise "trace failed: #{stderr}" unless status.success? trace_file = File.join(out_dir, 'trace.json') - trace = JSON.parse(File.read(trace_file)) if File.exist?(trace_file) + trace = filter_trace(JSON.parse(File.read(trace_file))) if File.exist?(trace_file) program_out = stdout.lines.reject { |l| l.start_with?('call ') || l.start_with?('return') }.join [trace, program_out] end @@ -46,7 +56,7 @@ def run_trace_with_separator(tracer_script, program_name, *args) ) raise "trace failed: #{stderr}" unless status.success? trace_file = File.join(out_dir, 'trace.json') - trace = JSON.parse(File.read(trace_file)) if File.exist?(trace_file) + trace = filter_trace(JSON.parse(File.read(trace_file))) if File.exist?(trace_file) program_out = stdout.lines.reject { |l| l.start_with?('call ') || l.start_with?('return') }.join [trace, program_out] end