Project

General

Profile

Actions

Bug #14702

closed

On Ruby 2.5.1, tracepoint isn't working on the file that is loaded by load_iseq

Added by makoto_tajitsu@hotmail.co.jp (Makoto Tajitsu) almost 6 years ago. Updated about 5 years ago.

Status:
Closed
Target version:
-
ruby -v:
ruby 2.5.1p57 (2018-03-29 revision 63029) [x86_64-darwin16]
[ruby-core:86626]

Description

On Ruby 2.5.1, when loading file with RubyVM::InstructionSequence.load_from_binary, TracePoint callback event is not working on loaded file.

Steps to reproduce

Ruby version.

$ ruby -v
# => ruby 2.5.1p57 (2018-03-29 revision 63029) [x86_64-darwin16]

The example with yomikomu gem which is simply used load_iseq and load_from_binary method to load file quickly is following.

$ YOMIKOMU_AUTO_COMPILE=true bundle exec irb

> TracePoint.trace(:line) { |tp| puts tp.lineno if tp.path == '/path/to/somefile.rb' }
# => #<TracePoint:enabled>

> load '/path/to/somefile.rb'
# 3
# 4
# ...

> require 'yomikomu'

> load '/path/to/somefile.rb'
# no tracepoint callback for line event

Result of reproduce process

tracepoint callback isn't called on loaded file by using load_iseq and load_from_binary.

Expected result and the reason why you expect

tracepoint callback should be called for any loaded file to debug with debugguer(e.g. byebug).

On Ruby 2.4.3, this example is working correctly, so tracepoint callback is called and output lineno to stdout when loaded file after require 'yomikomu'.

Actions #1

Updated by makoto_tajitsu@hotmail.co.jp (Makoto Tajitsu) almost 6 years ago

  • Description updated (diff)
Actions #2

Updated by makoto_tajitsu@hotmail.co.jp (Makoto Tajitsu) almost 6 years ago

  • Description updated (diff)
Actions #3

Updated by makoto_tajitsu@hotmail.co.jp (Makoto Tajitsu) almost 6 years ago

  • Description updated (diff)

Updated by makoto_tajitsu@hotmail.co.jp (Makoto Tajitsu) almost 6 years ago

  • Description updated (diff)

How is the issue?

In addition to above, I confirm the issue in following example that does not use 3rd party gem.

#!/usr/bin/env ruby

# Write ruby file
File.write('./loaded_file.rb', 'puts :hello')

# load file and write iseq file
iseq = RubyVM::InstructionSequence.compile_file('./loaded_file.rb')
File.write('./loaded_file.yarb', iseq.to_binary)

# define load_iseq
class RubyVM::InstructionSequence
  def self.load_iseq(fname)
    b = File.read('./loaded_file.yarb')
    RubyVM::InstructionSequence.load_from_binary(b)
  end
end

TracePoint.trace(:line) do |tp|
  puts "file: #{tp.path}, line: #{tp.lineno}" if tp.path =~ /loaded_file/
end

load './loaded_file.rb' # => on ruby 2.5.0 and 2.5.1, no tracepoint callback is.

Updated by ko1 (Koichi Sasada) over 5 years ago

  • Assignee set to ko1 (Koichi Sasada)
Actions #6

Updated by ko1 (Koichi Sasada) over 5 years ago

  • Status changed from Open to Closed

Applied in changeset trunk|r64514.


check trace flags at loading [Bug #14702]

  • iseq.c (iseq_init_trace): at ISeq loading time, we need to check
    ruby_vm_event_enabled_flags to turn on trace instructions.
    Seprate this checking code from finish_iseq_build() and make
    new function. iseq_ibf_load() calls this funcation after loading.

  • test/ruby/test_iseq.rb: add a test for this fix.

Actions #7

Updated by nagachika (Tomoyuki Chikanaga) over 5 years ago

  • Backport changed from 2.3: UNKNOWN, 2.4: UNKNOWN, 2.5: UNKNOWN to 2.3: UNKNOWN, 2.4: UNKNOWN, 2.5: REQUIRED

Updated by nagachika (Tomoyuki Chikanaga) over 5 years ago

  • Backport changed from 2.3: UNKNOWN, 2.4: UNKNOWN, 2.5: REQUIRED to 2.3: UNKNOWN, 2.4: UNKNOWN, 2.5: DONE

ruby_2_5 r64997 merged revision(s) 64514.

Updated by alanwu (Alan Wu) over 5 years ago

  • File 0001-Fix-TracePoint-for-nested-iseq-loaded-from-binary.patch added

Hello. I don't think this issue is fully fixed.
I have put together a patch that has a fix and tests that fail on both trunk and ruby_2_5 for your consideration:

I've opened up a ticket for this patch: #15270

    Fix TracePoint for nested iseq loaded from binary [Bug #14702]
    
    When loading iseq from binary while a TracePoint is on, we need to
    recompile instructions to their "trace_" variant. Before this commit
    we only recompiled instructions in the top level iseq, which meant
    that TracePoint was malfunctioning for code inside module/class/method
    definitions.
    
    * compile.c: Move rb_iseq_init_trace to rb_ibf_load_iseq_complete.
      It is called on all iseqs during loading.
    
    * test_iseq.rb: Test that tracepoints fire within children iseq when
      using load_from_binary.
Actions #10

Updated by alanwu (Alan Wu) over 5 years ago

  • File deleted (0001-Fix-TracePoint-for-nested-iseq-loaded-from-binary.patch)

Updated by fxn (Xavier Noria) about 5 years ago

Hi!

Rails 6 applcations have bootsnap and Zeitwerk enabled by default. Right now, that needs Ruby 2.6 because Zeitwerk sets a trace point on the :class event to support what I call "explicit namespaces".

Just wanted to let you know about this situation, in case you'd like to take it into account for the timeline to ship 2.5.4.

Actions

Also available in: Atom PDF

Like0
Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0