Issue #20299 has been updated by kjtsanaktsidis (KJ Tsanaktsidis). Hm. I see. Thanks for the report. The problem is the following sequence of operations: * `tp.enable` - This attaches a global event handler to fire the tracepoint for all threads * `tp.enable { ...` - When the block begins, it sets `target_th` on the tracepoint, but does not actually attach a thread-local handler, since a global handler is already set * ` ... }` - When the block ends, `rb_tracepoint_enable` is called again, since the tracepoint was already enabled, but that does nothing. * `tp.disable` - This sees that `target_th` is set, so tries to detach a thread-local event handler for the tracepoint. But, there _is_ no thread local handler, so nothing happens! However, it does have the effect of clearing `target_th` * `tp.disable` - Now that `target_th` is set, it tries to detach the global event handler, not the thread local one, so it succeeds. I'm not 100% sure what should happen here. We could make sure that `tracepoint.enable { ... }` does not actually set `target_th` if we're already tracing? That would make it a no-op, but it would have the somewhat surprising effect of causing this to happen: ``` trace = TracePoint.new(:line) {} puts trace.enabled? # true trace.enable do puts trace.enabled? # true trace.disable puts trace.enabled? # false end puts trace.enabled? # true, because the end of the enable block resets the state to how it was before. ``` Honestly I'm strugling to think of what sensible scenario there even is for mixing the block & non-block forms of `enable` on the same tracepoint, and I think that perhaps doing so should simply raise an argument error (like your second example does). ---------------------------------------- Bug #20299: Tracepoint staying enable after a disable https://bugs.ruby-lang.org/issues/20299#change-107190 * Author: MaxLap (Maxime Lapointe) * Status: Open * ruby -v: 3.3.0 * Backport: 3.0: UNKNOWN, 3.1: UNKNOWN, 3.2: UNKNOWN, 3.3: UNKNOWN ---------------------------------------- Problem is present in Ruby 3.2.2, 3.2.3, 3.3.0. Didn't check before. It seems that TracePoint can sometime be "stuck" enabled after using disabled once on it. Here is a reproduction step using a "check speed" method that just does some work and print out how long it takes. This makes it pretty clear when TracePoint was on. Put this in a Ruby file: ``` def check_speed(msg) t1 = Time.now.to_f a = 0 1000000.times { |i| a += 10 } t2 = Time.now.to_f puts "#{t2-t1} - #{msg}" end check_speed("before") # fast trace = TracePoint.new(:line) {} trace.enable check_speed("after enable") # slow trace.enable { check_speed("in block enable") # slow } check_speed("after block enable") # slow trace.disable check_speed("after disable") # slow !!!! trace.disable check_speed("after disable again") # fast !!!! # And yet, using enable multiple time doesn't have a "counter" or similar trace.enable trace.enable trace.enable check_speed("after triple enable") # slow trace.disable check_speed("after single disable") # fast ``` Running the file, we get this: ``` $ ruby -v ruby 3.3.0 (2023-12-25 revision 5124f9ac75) [x86_64-linux] $ ruby local.rb 0.03473854064941406 - before 0.18935227394104004 - after enable 0.17757630348205566 - in block enable 0.18320131301879883 - after block enable 0.1818866729736328 - after disable 0.03412747383117676 - after disable again 0.18405628204345703 - after triple enable 0.033496856689453125 - after single disable ``` The first "after disable" should probably have been fast. If it's possible to have multiple nested enable/disable, then one would instead assume that after the last "single disable", things would still be slow. Note: This code patterns comes directly for a ruby/spec: ctrl+f for "enables trace object on calling with a block if it was already enabled" I note that in Ruby 3.2, the timing are a lot less similar. I don't know why. It would seem like TracePoint got slower in Ruby 3.3.0. Is that worth checking out / making a distincct bug for? ``` $ rvm use 3.2.3 Using /home/max/.rvm/gems/ruby-3.2.3 $ ruby local.rb 0.03246927261352539 - before 0.07910513877868652 - after enable 0.10309600830078125 - in block enable 0.12397646903991699 - after block enable 0.07114601135253906 - after disable 0.028218746185302734 - after disable again 0.12534689903259277 - after triple enable 0.02810525894165039 - after single disable ``` -- https://bugs.ruby-lang.org/