Project

General

Profile

Actions

Bug #15634

closed

TracePoint seems to be skipping some methods.

Added by ioquatix (Samuel Williams) over 2 years ago. Updated about 1 month ago.

Status:
Closed
Priority:
Normal
Assignee:
-
Target version:
-
[ruby-core:91659]

Description

trace_point = TracePoint.new(:call, :return, :line, :c_call, :c_return, :b_call, :b_return) do |trace|
    puts [trace.path, trace.lineno].join(":")
end

trace_point.enable

values = {foo: 10}

def shell_escape(x)
    x
end

values.map{|key, value| [
    key.to_s.upcase,
    shell_escape(value) # TracePoint is never triggered for this line.
]}

Related issues

Related to Ruby master - Bug #14889: TracePoint for :line never seems to trigger on argument list. Maybe by design?ClosedActions

Updated by ioquatix (Samuel Williams) over 2 years ago

Here is more elaborate example:

#!/usr/bin/env ruby

trace_point = TracePoint.new(:call, :return, :line, :c_call, :c_return, :b_call, :b_return) do |trace|
    puts [trace.path, trace.lineno].join(":")
end

trace_point.enable

values = {foo: 10}

def shell_escape(x)
    x
end

values.map{|key, value| [
    key.to_s.upcase,
    shell_escape(value) # TracePoint is never triggered for this line.
]}

Here is output:

<internal:prelude>:137
<internal:prelude>:138
/private/var/folders/3x/tvygzl0s65520b6t4tzqbt980000gn/T/8efd0295-4252-4947-a870-2c636bf2e120:9
/private/var/folders/3x/tvygzl0s65520b6t4tzqbt980000gn/T/8efd0295-4252-4947-a870-2c636bf2e120:11
/private/var/folders/3x/tvygzl0s65520b6t4tzqbt980000gn/T/8efd0295-4252-4947-a870-2c636bf2e120:11
/private/var/folders/3x/tvygzl0s65520b6t4tzqbt980000gn/T/8efd0295-4252-4947-a870-2c636bf2e120:11
/private/var/folders/3x/tvygzl0s65520b6t4tzqbt980000gn/T/8efd0295-4252-4947-a870-2c636bf2e120:15
/private/var/folders/3x/tvygzl0s65520b6t4tzqbt980000gn/T/8efd0295-4252-4947-a870-2c636bf2e120:15
/private/var/folders/3x/tvygzl0s65520b6t4tzqbt980000gn/T/8efd0295-4252-4947-a870-2c636bf2e120:15
/private/var/folders/3x/tvygzl0s65520b6t4tzqbt980000gn/T/8efd0295-4252-4947-a870-2c636bf2e120:15
/private/var/folders/3x/tvygzl0s65520b6t4tzqbt980000gn/T/8efd0295-4252-4947-a870-2c636bf2e120:16
/private/var/folders/3x/tvygzl0s65520b6t4tzqbt980000gn/T/8efd0295-4252-4947-a870-2c636bf2e120:16
/private/var/folders/3x/tvygzl0s65520b6t4tzqbt980000gn/T/8efd0295-4252-4947-a870-2c636bf2e120:16
/private/var/folders/3x/tvygzl0s65520b6t4tzqbt980000gn/T/8efd0295-4252-4947-a870-2c636bf2e120:16
/private/var/folders/3x/tvygzl0s65520b6t4tzqbt980000gn/T/8efd0295-4252-4947-a870-2c636bf2e120:16
/private/var/folders/3x/tvygzl0s65520b6t4tzqbt980000gn/T/8efd0295-4252-4947-a870-2c636bf2e120:11
/private/var/folders/3x/tvygzl0s65520b6t4tzqbt980000gn/T/8efd0295-4252-4947-a870-2c636bf2e120:12
/private/var/folders/3x/tvygzl0s65520b6t4tzqbt980000gn/T/8efd0295-4252-4947-a870-2c636bf2e120:13
/private/var/folders/3x/tvygzl0s65520b6t4tzqbt980000gn/T/8efd0295-4252-4947-a870-2c636bf2e120:18
/private/var/folders/3x/tvygzl0s65520b6t4tzqbt980000gn/T/8efd0295-4252-4947-a870-2c636bf2e120:15
/private/var/folders/3x/tvygzl0s65520b6t4tzqbt980000gn/T/8efd0295-4252-4947-a870-2c636bf2e120:15

Line 17 (the one marked by comment) is never executed.

Updated by jeremyevans0 (Jeremy Evans) about 1 month ago

The reason there is no event emitted for Line 17 in the example (#note-1) is there is no new expression/statement on that line. It is a continuation of the previous expression. I think we should adjust the documentation for the :line event to reflect the current behavior, and submitted a pull request for that: https://github.com/ruby/ruby/pull/4589.

The alternative would be emitting line events at many more places than we do now. For example, do we want 1, 3, or 5 line events for this:

[
  1,
  2,
  3
]

I think trying to increase the number of line events would require a lot of work for very little practical gain. In other words, the cost of doing so is much higher than the benefits.

Actions #3

Updated by jeremyevans0 (Jeremy Evans) about 1 month ago

  • Related to Bug #14889: TracePoint for :line never seems to trigger on argument list. Maybe by design? added
Actions #4

Updated by jeremyevans (Jeremy Evans) about 1 month ago

  • Status changed from Open to Closed

Applied in changeset git|72a4e1d3bbbdfff71ec2c6b2ddb3b9323193cacd.


Tweak description of TracePoint :line event

"code" here is too ambiguous. TracePoint events only occur if there
is a new statement or expression on that line, not if the line
is a continuation of a previous statement or expression and there
is no new statement or expression on the line.

For example:

[
 foo,   # start of expression, line event
 bar    # continuation of expression, no line event
]

[
 foo,   # start of expression, line event
 (bar)  # new expression, line event
]

foo(    # start of expression, line event
  bar   # continuation of expression, no line event
)

foo(    # start of expression, line event
  (bar) # new expression, line event
)

Fixes [Bug #15634]

Updated by ioquatix (Samuel Williams) about 1 month ago

I wouldn't say this bug is fixed. Adding documentation just clarifies the current behaviour but does not help resolve or improve on the original problem.

I would say, the line tracepoint is confusing at best, as one might expect it to trigger for each "line" of executable code. The implementation obviously skips some cases, but documenting the cases that it skips does not help me much to improve the coverage computation.

Maybe the problem is the naming of the tracepoint - maybe it should be called "statement" or "top_level_expression".

Updated by jeremyevans0 (Jeremy Evans) about 1 month ago

ioquatix (Samuel Williams) wrote in #note-5:

I wouldn't say this bug is fixed. Adding documentation just clarifies the current behaviour but does not help resolve or improve on the original problem.

Well, it depends on whether you think the current behavior is a code bug or documentation bug. I don't think it is a code bug, because the code was not designed to give the behavior you want. Maybe that is a design flaw, but it's not a bug in the implementation. I agree with you that there is room for improvement in this area, but I think proposed improvements would be feature requests.

I would say, the line tracepoint is confusing at best, as one might expect it to trigger for each "line" of executable code. The implementation obviously skips some cases, but documenting the cases that it skips does not help me much to improve the coverage computation.

I agree that :line as a name is not completely accurate. With the example I gave in #note-2:

[
  1,
  2,
  3
]

You could reasonably assume either 3 or 5 :line events instead of the current 1.

Another issue I noticed with the :line coverage is the above example has the :line event as the first line, but if the array contains a non-literal, the :line event is on the second line.

Maybe the problem is the naming of the tracepoint - maybe it should be called "statement" or "top_level_expression".

The issue with either of those names is that it could be trigger multiple times on the same line, so it wouldn't be a replacement for the current :line event. I could see where they would be useful as additional events, though.

Actions

Also available in: Atom PDF