From: brodock@... Date: 2015-02-05T21:14:56+00:00 Subject: [ruby-core:68032] [ruby-trunk - Bug #10803] 2.1.5: rb_gc_mark() Issue #10803 has been updated by Gabriel Mazetto. I think I found a pattern that could help... I have a specific piece of code in my application that stress a File.open {|| } pattern. It probably should be optimized to not do so, but I believe that with that information, you can reproduce the bug and try to troubleshoot: ``` /myapp/models/components/default_field.rb:46:in `load_yml' /Users/brodock/.rvm/gems/ruby-2.1.5/gems/syck-1.0.5/lib/syck.rb:155:in `load_file' /Users/brodock/.rvm/gems/ruby-2.1.5/gems/syck-1.0.5/lib/syck.rb:155:in `open' /Users/brodock/.rvm/gems/ruby-2.1.5/gems/syck-1.0.5/lib/syck.rb:156:in `block in load_file' /Users/brodock/.rvm/gems/ruby-2.1.5/gems/syck-1.0.5/lib/syck.rb:145:in `load' /Users/brodock/.rvm/gems/ruby-2.1.5/gems/syck-1.0.5/lib/syck.rb:145:in `load' /Users/brodock/.rvm/gems/ruby-2.1.5/gems/syck-1.0.5/lib/syck.rb:145:in `read' -- C level backtrace information ------------------------------------------- 0 ruby 0x000000010c0bbe50 rb_vm_bugreport + 144 1 ruby 0x000000010bf6d9b1 report_bug + 305 2 ruby 0x000000010bf6d874 rb_bug + 180 3 ruby 0x000000010bf8e4e9 gc_mark_children + 2409 4 ruby 0x000000010bf9592f gc_marks_body + 479 5 ruby 0x000000010bf9379b garbage_collect_body + 859 6 ruby 0x000000010bf8c517 garbage_collect + 407 7 ruby 0x000000010bf92dad garbage_collect_with_gvl + 61 8 ruby 0x000000010bf8ecd4 objspace_xmalloc + 196 9 ruby 0x000000010c04f131 str_make_independent_expand + 81 10 ruby 0x000000010c04f31f rb_str_modify_expand + 351 11 ruby 0x000000010bfa76a7 io_read + 423 12 ruby 0x000000010c0b7d30 vm_call0_body + 2320 13 ruby 0x000000010c0a90bf rb_funcallv + 207 14 syck.bundle 0x000000010d9f4f1f rb_syck_io_str_read + 95 15 syck.bundle 0x000000010d9facd4 syck_parser_read + 292 16 syck.bundle 0x000000010d9fc2d3 sycklex_yaml_utf8 + 4755 17 syck.bundle 0x000000010d9f05b8 syckparse + 584 18 syck.bundle 0x000000010d9faf58 syck_parse + 248 19 syck.bundle 0x000000010d9f6484 syck_parser_load + 212 20 ruby 0x000000010c0ba657 vm_call_cfunc + 1063 21 ruby 0x000000010c0a172d vm_exec_core + 11933 22 ruby 0x000000010c0b0121 vm_exec + 129 23 ruby 0x000000010c0b4d55 invoke_block_from_c + 2213 24 ruby 0x000000010c0ac938 rb_yield + 184 25 ruby 0x000000010bf7714a rb_ensure + 170 26 ruby 0x000000010c0ba657 vm_call_cfunc + 1063 27 ruby 0x000000010c0a1563 vm_exec_core + 11475 28 ruby 0x000000010c0b0121 vm_exec + 129 29 ruby 0x000000010c0b4d55 invoke_block_from_c + 2213 30 ruby 0x000000010c0acaf8 rb_yield_values + 408 31 ruby 0x000000010bf9bd5c each_pair_i_fast + 28 32 ruby 0x000000010bf9c575 hash_foreach_iter + 37 33 ruby 0x000000010c04810e st_foreach_check + 718 34 ruby 0x000000010bf95f02 hash_foreach_call + 34 35 ruby 0x000000010bf7714a rb_ensure + 170 36 ruby 0x000000010bf99828 rb_hash_each_pair + 184 37 ruby 0x000000010c0ba657 vm_call_cfunc + 1063 38 ruby 0x000000010c0a1563 vm_exec_core + 11475 39 ruby 0x000000010c0b0121 vm_exec + 129 40 ruby 0x000000010c0b4d55 invoke_block_from_c + 2213 41 ruby 0x000000010c0ac938 rb_yield + 184 42 ruby 0x000000010bf33869 rb_ary_each + 73 43 ruby 0x000000010c0ba657 vm_call_cfunc + 1063 44 ruby 0x000000010c0b9fa2 vm_call_method + 866 45 ruby 0x000000010c0baf6c vm_call_opt_send + 588 46 ruby 0x000000010c0a1563 vm_exec_core + 11475 47 ruby 0x000000010c0b0121 vm_exec + 129 48 ruby 0x000000010c0b4d55 invoke_block_from_c + 2213 49 ruby 0x000000010c0ac938 rb_yield + 184 50 ruby 0x000000010bf67ba1 each_slice_i + 97 51 ruby 0x000000010c0b470a invoke_block_from_c + 602 52 ruby 0x000000010c0ac938 rb_yield + 184 53 ruby 0x000000010bf33869 rb_ary_each + 73 54 ruby 0x000000010c0b7d30 vm_call0_body + 2320 55 ruby 0x000000010c0ad098 iterate_method + 216 56 ruby 0x000000010c0aced9 rb_iterate + 441 57 ruby 0x000000010c0acfad rb_block_call + 45 58 ruby 0x000000010bf66024 enum_each_slice + 116 59 ruby 0x000000010c0ba657 vm_call_cfunc + 1063 60 ruby 0x000000010c0b9fa2 vm_call_method + 866 61 ruby 0x000000010c0a1563 vm_exec_core + 11475 62 ruby 0x000000010c0b0121 vm_exec + 129 63 ruby 0x000000010c0b6acf eval_string_with_cref + 1631 64 ruby 0x000000010c0ad321 rb_f_eval + 161 65 ruby 0x000000010c0ba657 vm_call_cfunc + 1063 66 ruby 0x000000010c0a172d vm_exec_core + 11933 67 ruby 0x000000010c0b0121 vm_exec + 129 68 ruby 0x000000010c0b4d55 invoke_block_from_c + 2213 69 ruby 0x000000010c0b63a1 loop_i + 49 70 ruby 0x000000010bf76df6 rb_rescue2 + 278 71 ruby 0x000000010c0ae673 rb_f_loop + 51 72 ruby 0x000000010c0ba657 vm_call_cfunc + 1063 73 ruby 0x000000010c0b9fa2 vm_call_method + 866 74 ruby 0x000000010c0a1563 vm_exec_core + 11475 75 ruby 0x000000010c0b0121 vm_exec + 129 76 ruby 0x000000010c0b4d55 invoke_block_from_c + 2213 77 ruby 0x000000010c0b6448 catch_i + 88 78 ruby 0x000000010c0ae059 rb_catch_protect + 185 79 ruby 0x000000010c0ae5ec rb_f_catch + 76 80 ruby 0x000000010c0ba657 vm_call_cfunc + 1063 81 ruby 0x000000010c0b9fa2 vm_call_method + 866 82 ruby 0x000000010c0a1563 vm_exec_core + 11475 83 ruby 0x000000010c0b0121 vm_exec + 129 84 ruby 0x000000010c0b4d55 invoke_block_from_c + 2213 85 ruby 0x000000010c0b6448 catch_i + 88 86 ruby 0x000000010c0ae059 rb_catch_protect + 185 87 ruby 0x000000010c0ae5ec rb_f_catch + 76 88 ruby 0x000000010c0ba657 vm_call_cfunc + 1063 89 ruby 0x000000010c0b9fa2 vm_call_method + 866 90 ruby 0x000000010c0a1563 vm_exec_core + 11475 91 ruby 0x000000010c0b0121 vm_exec + 129 92 ruby 0x000000010c0b0060 rb_iseq_eval + 288 93 ruby 0x000000010bf7b107 rb_load_internal0 + 311 94 ruby 0x000000010bf7a6fe rb_require_safe + 1598 95 ruby 0x000000010c0ba657 vm_call_cfunc + 1063 96 ruby 0x000000010c0b9fa2 vm_call_method + 866 97 ruby 0x000000010c0a172d vm_exec_core + 11933 98 ruby 0x000000010c0b0121 vm_exec + 129 99 ruby 0x000000010c0b10ac rb_iseq_eval_main + 396 100 ruby 0x000000010bf76284 ruby_exec_internal + 148 101 ruby 0x000000010bf761ae ruby_run_node + 78 102 ruby 0x000000010bdaa38f main + 79 -- Other runtime information ----------------------------------------------- ``` Here is the piece of code that gets executed million times (because it's a bulk import method): ``` def load_yml YAML.load_file(File.join(File.expand_path(File.dirname(__FILE__)), "default_fields.yml"))[yml_key] || {} end ``` ---------------------------------------- Bug #10803: 2.1.5: rb_gc_mark() https://bugs.ruby-lang.org/issues/10803#change-51418 * Author: Gabriel Mazetto * Status: Feedback * Priority: Normal * Assignee: * ruby -v: ruby 2.1.5p273 (2014-11-13 revision 48405) [x86_64-darwin14.0] * Backport: 2.0.0: UNKNOWN, 2.1: UNKNOWN, 2.2: UNKNOWN ---------------------------------------- ~~~ /opt/rubies/2.1.5/lib/ruby/gems/2.1.0/bundler/gems/syck-358913870211/lib/syck.rb:136: [BUG] rb_gc_mark(): 0x007f96aa63a888 is T_NONE ruby 2.1.5p273 (2014-11-13 revision 48405) [x86_64-darwin14.0] -- Control frame information ----------------------------------------------- c:0053 p:---- s:0202 e:000201 CFUNC :load c:0052 p:0011 s:0198 e:000197 METHOD /opt/rubies/2.1.5/lib/ruby/gems/2.1.0/bundler/gems/syck-358913870211/lib/syck.rb:136 c:0051 p:0009 s:0194 e:000193 BLOCK /opt/rubies/2.1.5/lib/ruby/gems/2.1.0/bundler/gems/syck-358913870211/lib/syck.rb:147 [FINISH] c:0050 p:---- s:0191 e:000190 CFUNC :open c:0049 p:0015 s:0187 e:000186 METHOD /opt/rubies/2.1.5/lib/ruby/gems/2.1.0/bundler/gems/syck-358913870211/lib/syck.rb:146 c:0048 p:0044 s:0183 e:000182 METHOD /myapp/app/models/component/default_field.rb:46 c:0047 p:0021 s:0180 e:000179 METHOD /myapp/app/models/component/default_field.rb:42 c:0046 p:0007 s:0177 e:000176 METHOD /myapp/app/models/component/default_field.rb:4 c:0045 p:0031 s:0174 e:000173 BLOCK /myapp/app/models/conversion/content_processor.rb:26 [FINISH] c:0044 p:---- s:0169 e:000168 CFUNC :each c:0043 p:0011 s:0166 e:000165 METHOD /myapp/app/models/conversion/content_processor.rb:24 c:0042 p:0013 s:0163 e:000162 METHOD /myapp/app/models/conversion/content_processor.rb:14 c:0041 p:0034 s:0160 e:000159 METHOD /myapp/app/models/conversion/conversion_importer.rb:32 c:0040 p:0032 s:0155 e:000153 BLOCK /myapp/app/models/conversion/conversion_importer.rb:26 [FINISH] c:0039 p:---- s:0151 e:000150 CFUNC :each c:0038 p:0015 s:0148 e:000147 METHOD /opt/rubies/2.1.5/lib/ruby/gems/2.1.0/gems/activerecord-3.2.18/lib/active_record/relation/delegation.rb:6 c:0037 p:0015 s:0143 E:001c30 METHOD /myapp/app/models/conversion/conversion_importer.rb:24 c:0036 p:0007 s:0139 e:000138 METHOD /myapp/app/models/conversion/conversion_importer.rb:10 c:0035 p:0073 s:0135 e:000134 METHOD /myapp/app/models/conversion/lead_importer.rb:45 c:0034 p:0019 s:0132 e:000131 METHOD /myapp/app/models/conversion/lead_importer.rb:15 c:0033 p:0030 s:0129 e:000128 METHOD /myapp/app/models/conversion.rb:83 c:0032 p:0026 s:0126 e:000125 METHOD /myapp/app/models/conversion.rb:17 c:0031 p:0031 s:0122 e:000121 BLOCK /myapp/app/models/lead/import.rb:206 c:0030 p:0193 s:0119 e:000118 METHOD /opt/rubies/2.1.5/lib/ruby/gems/2.1.0/gems/activerecord-3.2.18/lib/active_record/connection_adapters/abstract/database_statemen c:0029 p:0017 s:0110 e:000109 METHOD /opt/rubies/2.1.5/lib/ruby/gems/2.1.0/gems/activerecord-3.2.18/lib/active_record/transactions.rb:208 c:0028 p:0015 s:0105 E:000700 BLOCK /myapp/app/models/lead/import.rb:204 [FINISH] c:0027 p:---- s:0102 e:000101 IFUNC c:0026 p:---- s:0100 e:000099 CFUNC :each c:0025 p:---- s:0098 e:000097 CFUNC :each_slice c:0024 p:0024 s:0094 E:000958 METHOD /myapp/app/models/lead/import.rb:203 c:0023 p:0014 s:0091 E:000e48 METHOD /myapp/app/models/lead/import.rb:98 c:0022 p:0006 s:0088 E:001af8 EVAL (irb):2 [FINISH] c:0021 p:---- s:0086 e:000085 CFUNC :eval c:0020 p:0024 s:0079 E:0019b8 METHOD /opt/rubies/2.1.5/lib/ruby/2.1.0/irb/workspace.rb:86 c:0019 p:0025 s:0072 E:001a28 METHOD /opt/rubies/2.1.5/lib/ruby/2.1.0/irb/context.rb:380 c:0018 p:0022 s:0066 E:001b28 BLOCK /opt/rubies/2.1.5/lib/ruby/2.1.0/irb.rb:492 c:0017 p:0040 s:0058 E:001be8 METHOD /opt/rubies/2.1.5/lib/ruby/2.1.0/irb.rb:624 c:0016 p:0009 s:0053 E:001a98 BLOCK /opt/rubies/2.1.5/lib/ruby/2.1.0/irb.rb:489 c:0015 p:0118 s:0049 E:000a60 BLOCK /opt/rubies/2.1.5/lib/ruby/2.1.0/irb/ruby-lex.rb:247 [FINISH] c:0014 p:---- s:0046 e:000045 CFUNC :loop c:0013 p:0007 s:0043 E:000338 BLOCK /opt/rubies/2.1.5/lib/ruby/2.1.0/irb/ruby-lex.rb:233 [FINISH] c:0012 p:---- s:0041 e:000040 CFUNC :catch c:0011 p:0015 s:0037 E:000358 METHOD /opt/rubies/2.1.5/lib/ruby/2.1.0/irb/ruby-lex.rb:232 c:0010 p:0030 s:0034 E:002438 METHOD /opt/rubies/2.1.5/lib/ruby/2.1.0/irb.rb:488 c:0009 p:0008 s:0031 E:001468 BLOCK /opt/rubies/2.1.5/lib/ruby/2.1.0/irb.rb:397 [FINISH] c:0008 p:---- s:0029 e:000028 CFUNC :catch c:0007 p:0143 s:0025 E:0011e8 METHOD /opt/rubies/2.1.5/lib/ruby/2.1.0/irb.rb:396 c:0006 p:0195 s:0020 E:0026f0 METHOD /opt/rubies/2.1.5/lib/ruby/gems/2.1.0/gems/railties-3.2.18/lib/rails/commands/console.rb:47 c:0005 p:0011 s:0016 E:0006a0 METHOD /opt/rubies/2.1.5/lib/ruby/gems/2.1.0/gems/railties-3.2.18/lib/rails/commands/console.rb:8 c:0004 p:0426 s:0012 E:0022c8 TOP /opt/rubies/2.1.5/lib/ruby/gems/2.1.0/gems/railties-3.2.18/lib/rails/commands.rb:41 [FINISH] c:0003 p:---- s:0008 e:000007 CFUNC :require c:0002 p:0045 s:0004 E:000be8 EVAL script/rails:5 [FINISH] c:0001 p:0000 s:0002 E:000b18 TOP [FINISH] ~~~ I've experienced this problem with other gems that have C extensions, it's not deterministic. -- https://bugs.ruby-lang.org/