Bug #20577: FREE_AT_EXIT segfaulting after 32683aa1

• Status: Closed
• Assignee: -
• Target version: -
• ruby -v: ruby 3.4.0dev (2024-06-11T14:33:51Z master 32683aa18d) [x86_64-linux]
• Backport: 3.1: UNKNOWN, 3.2: UNKNOWN, 3.3: UNKNOWN

[mdalessio (Mike Dalessio)]

After commit 32683aa1 on master, using RUBY_FREE_AT_EXIT results in a segfault. When run with valgrind, many invalid reads are reported.

Repro with

RUBY_FREE_AT_EXIT=1 bundle exec /path/to/ruby -e 'puts RUBY_DESCRIPTION'

or for valgrind details

RUBY_FREE_AT_EXIT=1 bundle exec valgrind /path/to/ruby -e 'puts RUBY_DESCRIPTION'

Typical example valgrind error is:

==441955== Invalid read of size 4
==441955==    at 0x2C6F97: hash_table_index (id_table.c:132)
==441955==    by 0x2C6F97: rb_id_table_lookup (id_table.c:230)
==441955==    by 0x31AB50: cached_callable_method_entry (vm_method.c:1415)
==441955==    by 0x31AB50: callable_method_entry_or_negative (vm_method.c:1485)
==441955==    by 0x31C4EE: callable_method_entry (vm_method.c:1522)
==441955==    by 0x31C4EE: rb_callable_method_entry (vm_method.c:1529)
==441955==    by 0x18F370: obj_any_hash (hash.c:222)
==441955==    by 0x19F444: any_hash (hash.c:204)
==441955==    by 0x19F444: rb_any_hash (hash.c:260)
==441955==    by 0x19F444: ar_do_hash (hash.c:418)
==441955==    by 0x19F444: ar_delete (hash.c:1093)
==441955==    by 0x19F444: rb_hash_stlike_delete (hash.c:2385)
==441955==    by 0x1A0CCB: rb_hash_delete_entry (hash.c:2402)
==441955==    by 0x2C59B6: rb_gc_free_dsymbol (symbol.c:851)
==441955==    by 0x17AC53: obj_free (gc.c:3460)
==441955==    by 0x17D045: rb_objspace_call_finalizer_i (gc.c:4352)
==441955==    by 0x17D045: gc_each_object (gc.c:4302)
==441955==    by 0x17D045: rb_objspace_call_finalizer (gc.c:4401)
==441955==    by 0x162719: rb_ec_finalize (eval.c:164)
==441955==    by 0x162719: rb_ec_cleanup (eval.c:255)
==441955==    by 0x15CE09: rb_main (main.c:40)
==441955==    by 0x15CE09: main (main.c:59)
==441955==  Address 0x4ec4610 is 0 bytes inside a block of size 24 free'd
==441955==    at 0x484988F: free (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==441955==    by 0x175BD1: objspace_xfree (gc.c:12153)
==441955==    by 0x175BD1: objspace_xfree (gc.c:12084)
==441955==    by 0x175BD1: ruby_sized_xfree.constprop.0 (gc.c:12257)
==441955==    by 0x17A9A0: obj_free (gc.c:3293)
==441955==    by 0x17D045: rb_objspace_call_finalizer_i (gc.c:4352)
==441955==    by 0x17D045: gc_each_object (gc.c:4302)
==441955==    by 0x17D045: rb_objspace_call_finalizer (gc.c:4401)
==441955==    by 0x162719: rb_ec_finalize (eval.c:164)
==441955==    by 0x162719: rb_ec_cleanup (eval.c:255)
==441955==    by 0x15CE09: rb_main (main.c:40)
==441955==    by 0x15CE09: main (main.c:59)
==441955==  Block was alloc'd at
==441955==    at 0x4846828: malloc (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==441955==    by 0x189B0A: objspace_xmalloc0 (gc.c:11938)
==441955==    by 0x2C6EA6: rb_id_table_create (id_table.c:98)
==441955==    by 0x31AD99: cache_callable_method_entry (vm_method.c:1444)
==441955==    by 0x31AD99: callable_method_entry_or_negative (vm_method.c:1502)
==441955==    by 0x32A7DE: callable_method_entry (vm_method.c:1522)
==441955==    by 0x32A7DE: vm_respond_to (vm_method.c:2878)
==441955==    by 0x3305E3: check_funcall_respond_to (vm_eval.c:602)
==441955==    by 0x3305E3: rb_check_funcall_default_kw (vm_eval.c:676)
==441955==    by 0x20E896: convert_type_with_id (object.c:3131)
==441955==    by 0x20E896: rb_check_convert_type_with_id (object.c:3223)
==441955==    by 0x1672A7: rb_stat (file.c:1299)
==441955==    by 0x16E15E: rb_file_exist_p (file.c:1805)
==441955==    by 0x16E15E: rb_check_realpath_internal (file.c:4567)
==441955==    by 0x1D6639: get_loaded_features_index (load.c:415)
==441955==    by 0x1D6FB7: rb_provide_feature (load.c:703)
==441955==    by 0x1A2629: rb_call_inits (inits.c:64)
==441955==    by 0x162B67: ruby_setup (eval.c:86)
==441955==    by 0x162C1C: ruby_init (eval.c:98)
==441955==    by 0x15CDF7: rb_main (main.c:39)
==441955==    by 0x15CDF7: main (main.c:59)

I'm attaching a full log from my system. cc @peterzhu2118 (Peter Zhu)

[mdalessio (Mike Dalessio)]

One more note: I can't reliably reproduce this without bundle exec, but the project directory does not have a Gemfile and in case it's relevant here's my bundle env:

Environment

Bundler       2.6.0.dev
  Platforms   ruby, x86_64-linux
Ruby          3.4.0p-1 (2024-06-12 revision 1db19a2dbd7a8b981b2611359b6bf4547ea678f5) [x86_64-linux]
  Full Path   /home/flavorjones/.rbenv/versions/bisect-ruby/bin/ruby
  Config Dir  /home/flavorjones/.rbenv/versions/bisect-ruby/etc
RubyGems      3.6.0.dev
  Gem Home    /home/flavorjones/.rbenv/versions/bisect-ruby/lib/ruby/gems/3.4.0+0
  Gem Path    /home/flavorjones/.gem/ruby/3.4.0+0:/home/flavorjones/.rbenv/versions/bisect-ruby/lib/ruby/gems/3.4.0+0
  U
  User Path   /home/flavorjones/.gem/ruby/3.4.0+0
  Bin Dir     /home/flavorjones/.rbenv/versions/bisect-ruby/bin
Tools
  Git         2.43.0
  RVM         not installed
  rbenv       rbenv 1.2.0-87-ge8b7a27e
  chruby      not installed

Bundler Build Metadata

Built At          2024-06-12
Git SHA           unknown
Released Version  false

Bundler settings

gem.changelog
  Set for the current user (/home/flavorjones/.bundle/config): true
gem.ci
  Set for the current user (/home/flavorjones/.bundle/config): "github"
gem.linter
  Set for the current user (/home/flavorjones/.bundle/config): "standard"
gem.test
  Set for the current user (/home/flavorjones/.bundle/config): "minitest"
jobs
  Set for the current user (/home/flavorjones/.bundle/config): 4

[peterzhu2118 (Peter Zhu)]

Thanks for the report, Mike! I tried to reproduce this but I haven't been able to:

$ RUBY_FREE_AT_EXIT=1 bundle exec valgrind ruby -e 'puts RUBY_DESCRIPTION'
warning: Free at exit is experimental and may be unstable
==22116== Memcheck, a memory error detector
==22116== Copyright (C) 2002-2022, and GNU GPL'd, by Julian Seward et al.
==22116== Using Valgrind-3.20.0 and LibVEX; rerun with -h for copyright info
==22116== Command: ruby -e puts\ RUBY_DESCRIPTION
==22116== 
==22116== Warning: client switching stacks?  SP change: 0x1ffe8020e0 --> 0x1ffefff440
==22116==          to suppress, use: --max-stackframe=8377184 or greater
==22116== Warning: set address range perms: large range [0x6b10000, 0x1eb10000) (defined)
ruby: warning: Free at exit is experimental and may be unstable
==22116== Conditional jump or move depends on uninitialised value(s)
==22116==    at 0x45C15C: add_insn_info (compile.c:2415)
==22116==    by 0x45C15C: iseq_set_sequence (compile.c:2722)
==22116==    by 0x45C15C: iseq_setup (compile.c:1636)
==22116==    by 0x48020E: rb_iseq_compile_node (compile.c:978)
==22116==    by 0x1CC1EE: rb_iseq_new_with_opt (iseq.c:1005)
==22116==    by 0x4726CD: new_child_iseq (compile.c:1486)
==22116==    by 0x4726CD: iseq_compile_each0 (compile.c:10763)
==22116==    by 0x46FBBA: iseq_compile_each (compile.c:10233)
==22116==    by 0x46FBBA: compile_block (compile.c:4379)
==22116==    by 0x46FBBA: iseq_compile_each0 (compile.c:10263)
==22116==    by 0x4809E1: iseq_compile_each (compile.c:10233)
==22116==    by 0x4809E1: rb_iseq_compile_node (compile.c:908)
==22116==    by 0x1CC1EE: rb_iseq_new_with_opt (iseq.c:1005)
==22116==    by 0x4713C3: new_child_iseq (compile.c:1486)
==22116==    by 0x4713C3: iseq_compile_each0 (compile.c:10828)
==22116==    by 0x46FBBA: iseq_compile_each (compile.c:10233)
==22116==    by 0x46FBBA: compile_block (compile.c:4379)
==22116==    by 0x46FBBA: iseq_compile_each0 (compile.c:10263)
==22116==    by 0x480197: iseq_compile_each (compile.c:10233)
==22116==    by 0x480197: rb_iseq_compile_node (compile.c:943)
==22116==    by 0x1CC1EE: rb_iseq_new_with_opt (iseq.c:1005)
==22116==    by 0x1CC522: rb_iseq_new_top (iseq.c:887)
==22116== 
ruby 3.4.0dev (2024-05-01T14:52:53Z master 77f5301cd1) [x86_64-linux]
==22116== 
==22116== HEAP SUMMARY:
==22116==     in use at exit: 7,095 bytes in 16 blocks
==22116==   total heap usage: 133,216 allocs, 133,200 frees, 43,956,506 bytes allocated
==22116== 
==22116== LEAK SUMMARY:
==22116==    definitely lost: 0 bytes in 0 blocks
==22116==    indirectly lost: 0 bytes in 0 blocks
==22116==      possibly lost: 1,104 bytes in 1 blocks
==22116==    still reachable: 5,991 bytes in 15 blocks
==22116==         suppressed: 0 bytes in 0 blocks
==22116== Rerun with --leak-check=full to see details of leaked memory
==22116== 
==22116== Use --track-origins=yes to see where uninitialised values come from
==22116== For lists of detected and suppressed errors, rerun with: -s
==22116== ERROR SUMMARY: 2 errors from 1 contexts (suppressed: 0 from 0)

I'll try other things and will post an update if I find anything.

[mdalessio (Mike Dalessio)]

@peterzhu2118 (Peter Zhu) If it's helpful, the Nokogiri ruby-head CI jobs (run with ruby_memcheck) fail reliably:

• https://github.com/sparklemotion/nokogiri/actions/runs/9478882126/job/26116229709
• https://github.com/sparklemotion/nokogiri/actions/runs/9478882126/job/26116231097

[mdalessio (Mike Dalessio)]

I can also reproduce this by running ruby_memcheck's tests with ruby master.

[peterzhu2118 (Peter Zhu)]

I was able to reproduce this on nokogiri and prism test suites. I have a fix here: https://github.com/ruby/ruby/pull/10984

[peterzhu2118 (Peter Zhu)]

• Status changed from Open to Closed

Applied in changeset git|7c46aa5ed4573ca04e6ffe1b19191e8227db2ab3.

---

[Bug #20577] Fix freeing symbols when RUBY_FREE_AT_EXIT

Dynamic symbols point to a fstring. When we free the symbol, we hash the
fstring to remove it from the table. However, the fstring could have
already been freed, which can cause a crash.

This commit changes it to remove the reference to the fstring before
freeing the symbol so we can avoid this crash.