Bug #16889
closedTracePoint.enable { ... } also activates the TracePoint for other threads, even outside the block
Description
threads = []
inspects = []
trace = TracePoint.new(:line) do |tp|
threads << Thread.current
inspects << tp.inspect
end
done = false
thread = Thread.new do
Thread.pass until done
end
trace.enable do
line_event = true
done = true
sleep 1
end
thread.join
# Expected only within enable block (lines 14-16)
puts inspects
# Expected just 1
p threads.uniq
Results in:
$ ruby tpbug.rb
ruby tpbug.rb
#<TracePoint:line@tpbug.rb:14>
#<TracePoint:line@tpbug.rb:15>
#<TracePoint:line@tpbug.rb:16>
#<TracePoint:line@tpbug.rb:10>
[#<Thread:0x00005571134e3340 run>, #<Thread:0x00005571138ac828@tpbug.rb:9 dead>]
But I expected:
#<TracePoint:line@tpbug.rb:14>
#<TracePoint:line@tpbug.rb:15>
#<TracePoint:line@tpbug.rb:16>
[#<Thread:0x00005571134e3340 run>]
Because the RDoc says:
If a block is given, the trace will only be enabled within the scope of
the block.
For background I'm trying to improve the TracePoint specs in ruby/spec, but they are proving quite unreliable due to this.
@ko1 (Koichi Sasada) Thoughts?
Updated by Eregon (Benoit Daloze) over 4 years ago
Maybe enable(&block)
should behave like enable(target: block); disable
?
Updated by jeremyevans0 (Jeremy Evans) over 3 years ago
- Tracker changed from Bug to Feature
- ruby -v deleted (
ruby 2.6.6p146 (2020-03-31 revision 67876) [x86_64-linux]) - Backport deleted (
2.5: UNKNOWN, 2.6: UNKNOWN, 2.7: UNKNOWN)
Eregon (Benoit Daloze) wrote in #note-2:
Maybe
enable(&block)
should behave likeenable(target: block); disable
?
I looked into this. Implementing this fairly simple, but it breaks many tests and specs. The reason for this is that there are many tests and specs where this is not desired behavior, because they don't want to test tracing of the block itself, but tracing during the block.
Most of the breakage is actually that calling TracePoint#enable in a way that doesn't actually add any traces raises an error. Here's one such case, taken from test_tracepoint_thread
:
events = []
thread_self = nil
created_thread = nil
TracePoint.new(:thread_begin, :thread_end){|tp|
events << [Thread.current,
tp.event,
tp.lineno, #=> 0
tp.path, #=> nil
tp.binding, #=> nil
tp.defined_class, #=> nil,
tp.self.class # tp.self return creating/ending thread
]
}.enable{
created_thread = Thread.new{thread_self = self}
created_thread.join
}
events.reject!{|i| i[0] != created_thread}
Automatically making the block the target, similar to this code, results in an error:
events = []
thread_self = nil
created_thread = nil
block = proc{
created_thread = Thread.new{thread_self = self}
created_thread.join
}
TracePoint.new(:thread_begin, :thread_end){|tp|
events << [Thread.current,
tp.event,
tp.lineno, #=> 0
tp.path, #=> nil
tp.binding, #=> nil
tp.defined_class, #=> nil,
tp.self.class # tp.self return creating/ending thread
]
}.enable(target: block, &block)
# <internal:trace_point>:199:in `enable': can not enable any hooks (ArgumentError)
I'm guessing this is because :thread_begin and :thread_end events aren't triggered for code targets, unlike :line events.
Due to this issue, I don't think it makes sense to turn enable(&block)
into enable(target: block); disable
by default.
However, I think there value in making it nicer to enable only the targeting of the block. You can do this already, but it is clunky. In your example, you would do it like this:
threads = []
inspects = []
trace = TracePoint.new(:line) do |tp|
threads << Thread.current
inspects << tp.inspect
end
done = false
thread = Thread.new do
Thread.pass until done
end
block = proc do
line_event = true
done = true
sleep 1
end
trace.enable(target: block, &block)
thread.join
# Expected only within enable block (lines 14-16)
puts inspects
# Expected just 1
p threads.uniq
I propose we support target: :block
to support using the block passed to enable
as the target. This would enable the following API:
threads = []
inspects = []
trace = TracePoint.new(:line) do |tp|
threads << Thread.current
inspects << tp.inspect
end
done = false
thread = Thread.new do
Thread.pass until done
end
trace.enable(target: :block) do
line_event = true
done = true
sleep 1
end
thread.join
# Expected only within enable block (lines 14-16)
puts inspects
# Expected just 1
p threads.uniq
I've submitted a pull request that implements this: https://github.com/ruby/ruby/pull/4624.
Updated by Eregon (Benoit Daloze) over 3 years ago
The reason for this is that there are many tests and specs where this is not desired behavior, because they don't want to test tracing of the block itself, but tracing during the block.
Right, I guess the expectation is that .enable { ... }
also reports events from calls inside that block.
Maybe .enable { ... }
should enable events only on that Thread (or better, Fiber) then?
That feels intuitive and I think is good enough for compatibility, what do you think?
Updated by Eregon (Benoit Daloze) over 3 years ago
trace.enable(target: :block)
seems nice to me (WDYT @ko1 (Koichi Sasada)?).
But I think trace.enable { ... }
should not affect other Threads/Fiber, otherwise that form is just too confusing and error-prone.
Updated by jeremyevans0 (Jeremy Evans) over 3 years ago
Eregon (Benoit Daloze) wrote in #note-5:
But I think
trace.enable { ... }
should not affect other Threads/Fiber, otherwise that form is just too confusing and error-prone.
If you look at the tests, they expect that enable
is not limited to the current thread. The expected usage is tracing other threads during the duration of the block. You can already specify to only trace the current thread using: enable(target_thread: Thread.current)
. I do think enable
only affecting the current thread may be a more common desire, but I can also see that enable
allowing tracing other threads inside the block is also a reasonable use. I don't think it's worth breaking backwards compatibility to change the behavior.
Updated by mame (Yusuke Endoh) over 3 years ago
TracePoint#enable(target: :block)
does not follow events in a called method. Is this really intentional?
trace = TracePoint.new(:line) {|tp| p tp }
def foo
1
end
trace.enable do
foo
end
#=>
# #<TracePoint:line t.rb:8>
# #<TracePoint:line t.rb:4 in `foo'>
puts
trace.enable(target: :block) do
foo
end
#=>
# #<TracePoint:line t.rb:17>
Note that the second trace.enable
does not print #<TracePoint:line t.rb:4 in 'foo'>
.
Updated by ko1 (Koichi Sasada) over 3 years ago
+1 for Jeremy #6.
I also agree TP#enable{ ... }
should be thread-local without any options, but I don't think it is valuable to change the default behaver (break compatibility).
Updated by jeremyevans0 (Jeremy Evans) over 3 years ago
mame (Yusuke Endoh) wrote in #note-7:
TracePoint#enable(target: :block)
does not follow events in a called method. Is this really intentional?trace = TracePoint.new(:line) {|tp| p tp } def foo 1 end trace.enable do foo end #=> # #<TracePoint:line t.rb:8> # #<TracePoint:line t.rb:4 in `foo'> puts trace.enable(target: :block) do foo end #=> # #<TracePoint:line t.rb:17>
Note that the second
trace.enable
does not print#<TracePoint:line t.rb:4 in 'foo'>
.
This matches the behavior of passing the block explicitly and using it as the target:
trace = TracePoint.new(:line) {|tp| p tp }
def foo
1
end
trace.enable do
foo
end
#=>
# #<TracePoint:line t.rb:8>
# #<TracePoint:line t.rb:4 in `foo'>
puts
pr = proc do
foo
end
trace.enable(target: pr, &pr)
#<TracePoint:line t.rb:17>
So I think it is expected. My guess would be while the location of the trace point shows the point of call, it isn't triggered unless the method itself is targeted. If you target both the method and the block, you get both lines:
trace = TracePoint.new(:line) {|tp| p tp }
trace2 = TracePoint.new(:line) {|tp| p tp }
def foo
1
end
trace.enable do
foo
end
#=>
# #<TracePoint:line t.rb:8>
# #<TracePoint:line t.rb:4 in `foo'>
puts
pr = proc do
foo
end
trace2.enable(target: method(:foo)) do
trace.enable(target: pr, &pr)
end
# #<TracePoint:line -:18>
# #<TracePoint:line -:5 in `foo'>
Whether the current behavior of targeted traces is a bug, I'm not sure. If so, it isn't a bug in the target: :block
support, but a more general issue with targeted traces.
Updated by Eregon (Benoit Daloze) over 3 years ago
mame (Yusuke Endoh) wrote in #note-7:
Note that the second
trace.enable
does not print#<TracePoint:line t.rb:4 in 'foo'>
.
A very good point, that I thought about when talking a bit with Koichi about this, some time before filing this issue and then apparently forgot when filing the issue.
I do expect:
TracePoint.new(:line) {|tp| p tp }.enable do
foo
end
to report lines within that last block, and within foo
, so thread-local behavior in other words.
So I'd want tp.enable {}
to be like tp.enable(target_thread: Thread.current) {}
.
ko1 (Koichi Sasada) wrote in #note-8:
I also agree
TP#enable{ ... }
should be thread-local without any options, but I don't think it is valuable to change the default behaver (break compatibility).
Exactly. I think it could be worth it, because I think most people expect TP#enable {}
to be thread local and not affect other threads which are executing in random places completely unrelated to the block.
The way I see it is enable { ... }
should trace whatever is inside that block (including calls), but not other threads since they are not executing inside that block.
This is also why I filed it as a Bug, IMHO the current behavior is unexpected.
I guess the purpose of the current behavior is it behaves like open
and so enable { ... }
is like enable; ...; ensure; disable
.
And maybe initially TracePoint did not support tracing a particular Thread?
I think it would be worth to experiment how little it would break to make tp.enable {}
to be like tp.enable(target_thread: Thread.current) {}
.
IMHO it would be worth changing, but I can also see others have compatibility concerns.
If someone actually wants to enable for all threads, they could anyway do tp.enable; ...; ensure; tp.disable
, or tp.enable(target_thread: nil/:all/Thread.list)
.
If we keep the current behavior we should fix the docs, for me these docs clearly indicate thread-local behavior:
If a block is given, the trace will only be enabled within the scope of
the block.
trace.enabled?
#=> false
trace.enable do
trace.enabled?
# only enabled for this block
end
trace.enabled?
#=> false
i.e. "scope of the block" sounds like "events with this block call in the call stack" or "events within that block", but not the actual behavior "enable for all threads, and when quitting the block disable for all threads".
Regarding target: Proc
I think it's clearly documented to only trace the Proc and no calls within it (rdoc of TracePoint#enable
), so no objection to the behavior of enable(target:)
:
target, target_line and target_thread parameters are used to limit
tracing only to specified code objects. target should be a code object
for which RubyVM::InstructionSequence.of will return an instruction
sequence.
Updated by Eregon (Benoit Daloze) over 3 years ago
Actually thread-local might not be enough, we'd probably want Fiber local, i.e., events which are on the same execution stack and contain that enable block call on the stack.
Is there any way to have a TracePoint for a particular Fiber?
Updated by ko1 (Koichi Sasada) over 3 years ago
Eregon (Benoit Daloze) wrote in #note-11:
Actually thread-local might not be enough, we'd probably want Fiber local, i.e., events which are on the same execution stack and contain that enable block call on the stack.
Is there any way to have a TracePoint for a particular Fiber?
Just now, it is not provided.
Updated by mame (Yusuke Endoh) over 3 years ago
Eregon (Benoit Daloze) wrote in #note-10:
I do expect:
TracePoint.new(:line) {|tp| p tp }.enable do foo end
to report lines within that last block, and within
foo
, so thread-local behavior in other words.
So I'd wanttp.enable {}
to be liketp.enable(target_thread: Thread.current) {}
.
Agreed. I think thread-local behavior is more reasonable. So, the current target: :block
is not what you want, right?
Though I like thread-local behavior, I have some concerns:
-
tp.enable { Thread.new { foo }.join }
will not tracefoo
because it is run in another thread, but I'm unsure if this is expected. -
tp.enable
called with no block should trace events in all threads, right? It is a bit inconsistent, but perhaps changing this to thread-local will break Zeitwerk.
Updated by jeremyevans0 (Jeremy Evans) over 3 years ago
- Tracker changed from Feature to Bug
- Backport set to 2.6: UNKNOWN, 2.7: UNKNOWN, 3.0: UNKNOWN
This was discussed at the August 2021 developer meeting, and it was decided that TracePoint#enable with a block will be thread-local by default. However, that change will not take place until after Ruby 3.1. I'm switching this back to bug.
Updated by Eregon (Benoit Daloze) over 3 years ago
mame (Yusuke Endoh) wrote in #note-13:
Agreed. I think thread-local behavior is more reasonable. So, the current
target: :block
is not what you want, right?
Indeed. I'm not against it but I don't think it's necessary or so helpful.
Though I like thread-local behavior, I have some concerns:
tp.enable { Thread.new { foo }.join }
will not tracefoo
because it is run in another thread, but I'm unsure if this is expected.
I think it is expected. foo
is not on the call stack of that tp.enable
(it does have that TracePoint#enable
as a caller).
With that logic I would also prefer if tp.enable { Fiber.new { foo }.resume }
does not trace foo
, but it is less important, as that could only happen if the enable
blocks switches Fibers (probably rare).
Currently, Thread.new { sleep 1; foo }; tp.enable { bar }
will trace bar
(expected) but also foo
(I find that unexpected/unintuitive).
tp.enable
called with no block should trace events in all threads, right? It is a bit inconsistent, but perhaps changing this to thread-local will break Zeitwerk.
Yes, tp.enable
(no block) should trace events everywhere, I think that's intuitive, it doesn't provide any "target" or "context" (a block) so it's global.
Updated by jeremyevans0 (Jeremy Evans) almost 3 years ago
I submitted a pull request to make enable
affect the current thread by default: https://github.com/ruby/ruby/pull/5359
The power_assert bundled gem tests fail with it, so power_assert will need to be updated before this can be merged. Just adding target_thread: nil
to the enable
calls does not appear to be enough to make power_assert work.
Updated by jeremyevans (Jeremy Evans) over 2 years ago
- Status changed from Open to Closed
Applied in changeset git|9c1d32a7ada794ecd0356d56f7be3cdf3982d8ac.
Make TracePoint#enable with block target current thread by default
If TracePoint#enable is passed a block, it previously started
the trace on all threads. This changes it to trace only the
current thread by default. To limit the scope of the change,
the current thread is only used by default if target and
target_line are both nil. You can pass target_thread: nil
to enable tracing on all threads, to get the previous
default behavior.
Fixes [Bug #16889]