Skip to content

Workaround for mmtk-core logging issue #22

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Aug 31, 2022
Merged

Workaround for mmtk-core logging issue #22

merged 1 commit into from
Aug 31, 2022

Conversation

chrisseaton
Copy link
Collaborator

Workaround for mmtk/mmtk-core#654

@chrisseaton chrisseaton requested a review from wks August 30, 2022 12:47
@chrisseaton chrisseaton self-assigned this Aug 30, 2022
Copy link

@wks wks left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM. When the PR mmtk/mmtk-core#655 is merged, I'll revert this change.

@wks wks merged commit de7fb26 into mmtk Aug 31, 2022
wks added a commit that referenced this pull request Aug 31, 2022
This reverts commit de7fb26.

The upstream fixed the printing issue in:
mmtk/mmtk-core#655
@chrisseaton chrisseaton deleted the test-workaround branch September 6, 2022 11:17
wks pushed a commit that referenced this pull request Dec 5, 2024
[Bug #20921]

When we create a cache entry for a constant, the following sequence of
events could happen:

- vm_track_constant_cache is called to insert a constant cache.
- In vm_track_constant_cache, we first look up the ST table for the ID
  of the constant. Assume the ST table exists because another iseq also
  holds a cache entry for this ID.
- We then insert into this ST table with the iseq_inline_constant_cache.
- However, while inserting into this ST table, it allocates memory, which
  could trigger a GC. Assume that it does trigger a GC.
- The GC frees the one and only other iseq that holds a cache entry for
  this ID.
- In remove_from_constant_cache, it will appear that the ST table is now
  empty because there are no more iseq with cache entries for this ID, so
  we free the ST table.
- We complete GC and continue our st_insert. However, this ST table has
  been freed so we now have a use-after-free.

This issue is very hard to reproduce, because it requires that the GC runs
at a very specific time. However, we can make it show up by applying this
patch which runs GC right before the st_insert to mimic the st_insert
triggering a GC:

    diff --git a/vm_insnhelper.c b/vm_insnhelper.c
    index 3cb23f0..a93998136a 100644
    --- a/vm_insnhelper.c
    +++ b/vm_insnhelper.c
    @@ -6338,6 +6338,10 @@ vm_track_constant_cache(ID id, void *ic)
            rb_id_table_insert(const_cache, id, (VALUE)ics);
        }

    +    if (id == rb_intern("MyConstant")) rb_gc();
    +
        st_insert(ics, (st_data_t) ic, (st_data_t) Qtrue);
    }

And if we run this script:

    Object.const_set("MyConstant", "Hello!")

    my_proc = eval("-> { MyConstant }")
    my_proc.call

    my_proc = eval("-> { MyConstant }")
    my_proc.call

We can see that ASAN outputs a use-after-free error:

    ==36540==ERROR: AddressSanitizer: heap-use-after-free on address 0x606000049528 at pc 0x000102f3ceac bp 0x00016d607a70 sp 0x00016d607a68
    READ of size 8 at 0x606000049528 thread T0
        #0 0x102f3cea8 in do_hash st.c:321
        #1 0x102f3ddd0 in rb_st_insert st.c:1132
        #2 0x103140700 in vm_track_constant_cache vm_insnhelper.c:6345
        #3 0x1030b91d8 in vm_ic_track_const_chain vm_insnhelper.c:6356
        #4 0x1030b8cf8 in rb_vm_opt_getconstant_path vm_insnhelper.c:6424
        #5 0x1030bc1e0 in vm_exec_core insns.def:263
        #6 0x1030b55fc in rb_vm_exec vm.c:2585
        #7 0x1030fe0ac in rb_iseq_eval_main vm.c:2851
        #8 0x102a82588 in rb_ec_exec_node eval.c:281
        #9 0x102a81fe0 in ruby_run_node eval.c:319
        #10 0x1027f3db4 in rb_main main.c:43
        #11 0x1027f3bd4 in main main.c:68
        #12 0x183900270  (<unknown module>)

    0x606000049528 is located 8 bytes inside of 56-byte region [0x606000049520,0x606000049558)
    freed by thread T0 here:
        #0 0x104174d40 in free+0x98 (libclang_rt.asan_osx_dynamic.dylib:arm64e+0x54d40)
        #1 0x102ada89c in rb_gc_impl_free default.c:8183
        #2 0x102ada7dc in ruby_sized_xfree gc.c:4507
        #3 0x102ac4d34 in ruby_xfree gc.c:4518
        #4 0x102f3cb34 in rb_st_free_table st.c:663
        #5 0x102bd52d8 in remove_from_constant_cache iseq.c:119
        #6 0x102bbe2cc in iseq_clear_ic_references iseq.c:153
        #7 0x102bbd2a0 in rb_iseq_free iseq.c:166
        #8 0x102b32ed0 in rb_imemo_free imemo.c:564
        #9 0x102ac4b44 in rb_gc_obj_free gc.c:1407
        #10 0x102af4290 in gc_sweep_plane default.c:3546
        #11 0x102af3bdc in gc_sweep_page default.c:3634
        #12 0x102aeb140 in gc_sweep_step default.c:3906
        #13 0x102aeadf0 in gc_sweep_rest default.c:3978
        #14 0x102ae4714 in gc_sweep default.c:4155
        #15 0x102af8474 in gc_start default.c:6484
        #16 0x102afbe30 in garbage_collect default.c:6363
        #17 0x102ad37f0 in rb_gc_impl_start default.c:6816
        #18 0x102ad3634 in rb_gc gc.c:3624
        #19 0x1031406ec in vm_track_constant_cache vm_insnhelper.c:6342
        #20 0x1030b91d8 in vm_ic_track_const_chain vm_insnhelper.c:6356
        #21 0x1030b8cf8 in rb_vm_opt_getconstant_path vm_insnhelper.c:6424
        #22 0x1030bc1e0 in vm_exec_core insns.def:263
        #23 0x1030b55fc in rb_vm_exec vm.c:2585
        #24 0x1030fe0ac in rb_iseq_eval_main vm.c:2851
        #25 0x102a82588 in rb_ec_exec_node eval.c:281
        #26 0x102a81fe0 in ruby_run_node eval.c:319
        #27 0x1027f3db4 in rb_main main.c:43
        #28 0x1027f3bd4 in main main.c:68
        #29 0x183900270  (<unknown module>)

    previously allocated by thread T0 here:
        #0 0x104174c04 in malloc+0x94 (libclang_rt.asan_osx_dynamic.dylib:arm64e+0x54c04)
        #1 0x102ada0ec in rb_gc_impl_malloc default.c:8198
        #2 0x102acee44 in ruby_xmalloc gc.c:4438
        #3 0x102f3c85c in rb_st_init_table_with_size st.c:571
        #4 0x102f3c900 in rb_st_init_table st.c:600
        #5 0x102f3c920 in rb_st_init_numtable st.c:608
        #6 0x103140698 in vm_track_constant_cache vm_insnhelper.c:6337
        #7 0x1030b91d8 in vm_ic_track_const_chain vm_insnhelper.c:6356
        #8 0x1030b8cf8 in rb_vm_opt_getconstant_path vm_insnhelper.c:6424
        #9 0x1030bc1e0 in vm_exec_core insns.def:263
        #10 0x1030b55fc in rb_vm_exec vm.c:2585
        #11 0x1030fe0ac in rb_iseq_eval_main vm.c:2851
        #12 0x102a82588 in rb_ec_exec_node eval.c:281
        #13 0x102a81fe0 in ruby_run_node eval.c:319
        #14 0x1027f3db4 in rb_main main.c:43
        #15 0x1027f3bd4 in main main.c:68
        #16 0x183900270  (<unknown module>)

This commit fixes this bug by adding a inserting_constant_cache_id field
to the VM, which stores the ID that is currently being inserted and, in
remove_from_constant_cache, we don't free the ST table for ID equal to
this one.

Co-Authored-By: Alan Wu <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants