Feature #11725
closeddebugging support for frozen string literal
Description
Background¶
Debug frozen string literal is difficult because frozen string can be modified at far from created locations. For example, library X creates one string and modify this string is common situation. Also library X can pass the created string to library Y and also Y passes it to library Z. Clients receives a string from Z, then clients can not understand where the created location and can not debug it.
To help such situation, I introduced --enable-frozen-string-literal-debug option (a command line option and a compile option). This option enable to embed created location information into frozen string and to display RuntimeError message with this location information such as:
../../trunk/test.rb:21:in `<main>': can't modify frozen String, created at ../../trunk/test.rb:17 (RuntimeError)
(maybe only few people knows about this feature because NEWS doesn't describe it)
Proposal: Make it as default behavior¶
At first, I introduced this option as an optional feature because this option seems slow down applications.
However, including this information for sting literals is not so big impact because adding information for each string literal only at compile time. Another drawback is that we can't de-duplicate same frozen strings, but it is trivial issue.
One problem is string interpolation. Adding debug information for such dynamically created strings is not so easy. So I leave --enable-frozen-string-literal-debug for this type of strings. It is too long to use it, so -d or --debug option should enable this feature.
Conclusion:
- adding string literals as default.
- --enable-frozen-string-literal-debug for string interpolation. -d or --debug also enable this feature.
I hope we can change every string literals to frozen strings.
Any comments are welcome.
Naming¶
Now, I prefer --debug-frozen-string-literal than --enable-frozen-string-literal-debug.
Misc: benchmark script and result¶
require 'benchmark'
N = 5_000_000
def static_test1
"foo"
end
def static_test2
"foo".freeze
end
line = __LINE__ + 1
RubyVM::InstructionSequence.compile(%q{
def static_test3
"foo"
end
}, __FILE__, __FILE__, line, {frozen_string_literal: true}).eval
line = __LINE__ + 1
RubyVM::InstructionSequence.compile(%q{
def static_test4
"foo"
end
}, __FILE__, __FILE__, line, {frozen_string_literal: true, frozen_string_literal_debug: true}).eval
S = 'baz'
def dynamic_test1
"foo#{S}bar"
end
def dynamic_test2
"foo#{S}bar".freeze
end
line = __LINE__ + 1
RubyVM::InstructionSequence.compile(%q{
def dynamic_test3
"foo#{S}bar"
end
}, __FILE__, __FILE__, line, {frozen_string_literal: true}).eval
line = __LINE__ + 1
RubyVM::InstructionSequence.compile(%q{
def dynamic_test4
"foo#{S}bar"
end
}, __FILE__, __FILE__, line, {frozen_string_literal: true, frozen_string_literal_debug: true}).eval
Benchmark.bmbm{|x|
x.report('STATIC: without freeze' ){N.times{static_test1}}
x.report('STATIC: freeze by method'){N.times{static_test2}}
x.report('STATIC: freeze by pragma'){N.times{static_test3}}
x.report('STATIC: freeze by pragma/debug'){N.times{static_test3}}
x.report('DYNAMIC:without freeze' ){N.times{dynamic_test1}}
x.report('DYNAMIC:freeze by method'){N.times{dynamic_test2}}
x.report('DYNAMIC:freeze by pragma'){N.times{dynamic_test3}}
x.report('DYNAMIC:freeze by pragma/debug'){N.times{dynamic_test4}}
}
# error message check
['static', 'dynamic'].each{|feature|
(1..4).each{|type|
begin
m = "#{feature}_test#{type}"
send(m) << "str"
rescue RuntimeError => e
p [m, e]
else
p [m, nil]
end
}
}
user system total real
STATIC: without freeze 0.550000 0.000000 0.550000 ( 0.545465)
STATIC: freeze by method 0.330000 0.000000 0.330000 ( 0.337528)
STATIC: freeze by pragma 0.360000 0.000000 0.360000 ( 0.366031)
STATIC: freeze by pragma/debug 0.360000 0.000000 0.360000 ( 0.353534)
DYNAMIC:without freeze 1.230000 0.000000 1.230000 ( 1.230027)
DYNAMIC:freeze by method 1.580000 0.000000 1.580000 ( 1.585025)
DYNAMIC:freeze by pragma 1.420000 0.000000 1.420000 ( 1.424006)
DYNAMIC:freeze by pragma/debug 3.510000 0.000000 3.510000 ( 3.510279)
# error message check results
["static_test1", nil]
["static_test2", #<RuntimeError: can't modify frozen String>]
["static_test3", #<RuntimeError: can't modify frozen String, created at ../../trunk/test.rb:15>]
["static_test4", #<RuntimeError: can't modify frozen String, created at ../../trunk/test.rb:22>]
["dynamic_test1", nil]
["dynamic_test2", #<RuntimeError: can't modify frozen String>]
["dynamic_test3", #<RuntimeError: can't modify frozen String>]
["dynamic_test4", #<RuntimeError: can't modify frozen String, created at ../../trunk/test.rb:45>]
Updated by ko1 (Koichi Sasada) almost 9 years ago
- Status changed from Open to Closed
Applied in changeset r52688.
-
compile.c (iseq_compile_each): add debug information to NODE_STR
strings as default.
[Feature #11725] -
insns.def (freezestring): add new instruction to support adding
debug information for dynamically constracted strings. -
compile.c (iseq_compile_each): support adding debug information
for NODE_DSTR with freezestring instruction. -
error.c (rb_error_frozen): change the debug information ID name
id_debug_created_info and this field should have a 2 element array
containing path and line information. -
defs/id.def: ditto.
-
test/ruby/test_rubyoptions.rb: catch up this fix.
-
test/ruby/test_iseq.rb: now frozen strings are not same.
Updated by nobu (Nobuyoshi Nakada) almost 9 years ago
You run static_test3
twice, not static_test4
.
Updated by ko1 (Koichi Sasada) over 8 years ago
- Status changed from Closed to Assigned
We found performance regression with this feature.
"foo".dup with frozen literal also copy location information.
Quoted from https://bugs.ruby-lang.org/issues/11782#change-55313
# frozen-string-literal: true
user system total real
5.850000 0.010000 5.860000 ( 5.858450)
0.780000 0.000000 0.780000 ( 0.780911)
0.340000 0.000000 0.340000 ( 0.351072)
0.530000 0.000000 0.530000 ( 0.529234)
Too slow on "'foo'.dup" (a result on first line).
Nobu found the reason why it is slow.
And reason is implicit debug information.
String#dup copys with such debug information.
So I decide to withdraw the proposal of debugging support by default.
Same as dynamically created string, debug information is added for static string literal
iff --debug or --debug=frozen-string-literal is specified.
$ ./miniruby -I../../trunk/lib -I. -I.ext/common ../../trunk/test.rb
Rehearsal -------------------------------------------
.dup 2.280000 0.000000 2.280000 ( 2.280500)
+@ 0.770000 0.000000 0.770000 ( 0.767608)
.freeze 0.340000 0.000000 0.340000 ( 0.343781)
-@ 0.480000 0.000000 0.480000 ( 0.479379)
---------------------------------- total: 3.870000sec
user system total real
.dup 2.260000 0.000000 2.260000 ( 2.260352)
+@ 0.770000 0.000000 0.770000 ( 0.771664)
.freeze 0.350000 0.000000 0.350000 ( 0.345739)
-@ 0.470000 0.000000 0.470000 ( 0.471908)
$ ./miniruby --debug -I../../trunk/lib -I. -I.ext/common ../../trunk/test.rb
Rehearsal -------------------------------------------
.dup 5.470000 0.000000 5.470000 ( 5.483195)
+@ 0.790000 0.000000 0.790000 ( 0.789157)
.freeze 0.340000 0.000000 0.340000 ( 0.342538)
-@ 0.470000 0.000000 0.470000 ( 0.473341)
---------------------------------- total: 7.070000sec
user system total real
.dup 5.510000 0.010000 5.520000 ( 5.519788)
+@ 0.770000 0.000000 0.770000 ( 0.767551)
.freeze 0.340000 0.000000 0.340000 ( 0.342797)
-@ 0.470000 0.000000 0.470000 ( 0.473512)
Benchmark program:
# frozen-string-literal: true
require 'benchmark'
N = 10_000_000
Benchmark.bmbm{|x|
x.report('.dup'){
N.times{ 'foo'.dup }
}
x.report('+@'){
N.times{ +'foo' }
}
x.report('.freeze'){
N.times{ 'foo'.freeze }
}
x.report('-@'){
N.times{ -'foo' }
}
}
Updated by ko1 (Koichi Sasada) over 8 years ago
- Status changed from Assigned to Closed
Applied in changeset r53009.
-
compile.c (iseq_compile_each): do not add debug information
without --debug or --debug=frozen-string-literal option
because String#dup slows down with debug information.
[Feature #11725] -
NEWS: apply about it.
-
test/ruby/test_rubyoptions.rb: catch up this fix with refactoring.