Issue #20587 has been updated by ivoanjo (Ivo Anjo). jeremyevans0 (Jeremy Evans) wrote in #note-2:

@ivoanjo Can you be specific about which places this affects? I examined all `opendir` calls in `dir.c`:

* Called in `nogvl_opendir` * Called in `opendir_without_gvl` when VM is not initialized * Called in `nogvl_opendir_at` * Called in `nogvl_dir_empty_p`

Tracing those function calls, if the VM is initialized, it appears that all calls use the `IO_WITHOUT_GVL` macro to release the GVL around the call.

Hey Jeremy, thanks for taking a look at this! You are right -- I think I was overeager in including `readdir` on the list. I'll update my original description to correct for this. Here's my attempt at a more specific report of blocking calls while holding the GVL in `dir.c` (I've omitted cases where the GVL is released): * `fdopendir` -> called by `dir_s_for_fd` * `readdir` -> called by `dir_read`, `dir_each_entry`, `glob_helper`, `glob_getent` * `chdir` -> called by `dir_chdir0` (Although this one is somewhat weird already so perhaps it being blocking is not the weirdest part?) * `fchdir` -> called by `dir_fchdir` (same as `chrdir`) * `chroot` -> called by `dir_s_chroot` * `lstat` -> called by `do_lstat` * `stat` -> called by `do_stat` * `fstatat` -> called by `do_stat`/`do_lstat` * `fgetattrlist` -> called by `need_normalization`, `is_case_sensitive` * `getattrlist` -> called by `is_case_sensitive`, `replace_real_basename`, `rb_dir_s_empty_p`, `need_normalization`, `dir_initialize` * `getpwnam` -> called by `dir_s_home` ---------------------------------------- Bug #20587: dir.c calls blocking filesystem APIs/system calls while holding the GVL https://bugs.ruby-lang.org/issues/20587#change-109041 * Author: ivoanjo (Ivo Anjo) * Status: Open * Backport: 3.1: UNKNOWN, 3.2: UNKNOWN, 3.3: UNKNOWN ---------------------------------------- Hey! I work for Datadog on the Ruby profiler part of the [`datadog` (previously `ddtrace`)](https://github.com/datadog/dd-trace-rb) gem. While I was investigating https://bugs.ruby-lang.org/issues/20586, I spotted that there's a number of cases where, in `dir.c`, blocking system calls are being made (e.g. `readdir()`, `opendir()`, etc) without releasing the GVL. This means that if they block for a long time (as happens in the gcsfuse example in https://bugs.ruby-lang.org/issues/20586 ), the Ruby VM will just be blocked and not make any progress. The combination of not releasing the GVL + slow system calls actually makes the issue in https://bugs.ruby-lang.org/issues/20586 more likely to happen with the Datadog profiler, although even if the code releases the GVL the underlying issue could still happen, and this is why I decided to file this bug separately. -- https://bugs.ruby-lang.org/

Issue #20587 has been updated by ivoanjo (Ivo Anjo). File repro.rb added File hello.c added Nice! I've tried the PR and it actually makes the issue in https://bugs.ruby-lang.org/issues/20586#How-to-reproduce disappear in my tests. (It does not fully solve the issue, but what made it trigger a lot more often was that the `readdir` call blocked with the GVL held, since the Datadog profiler tries to interrupt only threads holding the GVL. With the GVL released, this can only happen in the remote chance the profiler decided to interrupt the thread just as it was preparing to call `readdir`). I also decided recover an old experiment I had to try to trigger some of these problems using a custom "adversarial" FUSE filesystem. Here's my script to trigger the syscalls: ```ruby $liveness = true $looping = false liveness_check = Thread.new do print "Is Ruby alive? (Should print every 0.1s) " while $liveness do print '.' before_sleep = Time.now $looping = true sleep 0.1 delay = Time.now - before_sleep puts "\n[HICCUP -- VM was probably blocked for #{delay - 0.1}s!]" if delay > 0.5 end end Thread.pass while !$looping directory = ARGV.last result = case ARGV.first.to_sym when :readdir d = Dir.new(directory) print "(Opened!)" d.children when :fdopendir # This one doesn't seem to work as a reproducer, the opendir for d0 seems to get reused by libc and that one already # released the GVL raise 'Broken?' d0 = Dir.new(directory) d1 = Dir.for_fd(d0.fileno) d1.to_s when :chdir Dir.chdir(directory) { } when :fchdir d = Dir.new(directory) print "(Opened!)" d.chdir { } when :chroot begin Dir.chroot(directory) rescue => e e end when :lstat Dir.glob("#{directory}/*", File::FNM_DOTMATCH) when :stat Dir.glob("#{directory}/", File::FNM_DOTMATCH) when :fstatat raise 'Did not figure out this one?' else raise "Unknown syscall #{ARGV.first}" end $liveness = false liveness_check.join puts "\n#{result.inspect}" ``` ...and here's how it looks before your PR: ``` $ ./miniruby repro.rb readdir /home/ivo.anjo/tmp-hello-mount-deleteme Is Ruby alive? (Should print every 0.1s) ........................................(Opened!) [HICCUP -- VM was probably blocked for 1.9858527449999999s!] ["hello"] $ ./miniruby repro.rb chdir /home/ivo.anjo/tmp-hello-mount-deleteme Is Ruby alive? (Should print every 0.1s) . [HICCUP -- VM was probably blocked for 1.9008266639999998s!] nil $ ./miniruby repro.rb fchdir /home/ivo.anjo/tmp-hello-mount-deleteme Is Ruby alive? (Should print every 0.1s) ........................................(Opened!) [HICCUP -- VM was probably blocked for 1.987699879s!] nil $ ./miniruby repro.rb chroot /home/ivo.anjo/tmp-hello-mount-deleteme Is Ruby alive? (Should print every 0.1s) . [HICCUP -- VM was probably blocked for 1.9008783179999997s!] #<Errno::EPERM: Operation not permitted @ dir_s_chroot - /home/ivo.anjo/tmp-hello-mount-deleteme> $ ./miniruby repro.rb lstat /home/ivo.anjo/tmp-hello-mount-deleteme Is Ruby alive? (Should print every 0.1s) ........................................ [HICCUP -- VM was probably blocked for 3.9877458889999997s!] ["/home/ivo.anjo/tmp-hello-mount-deleteme/.", "/home/ivo.anjo/tmp-hello-mount-deleteme/hello"] $ ./miniruby repro.rb stat /home/ivo.anjo/tmp-hello-mount-deleteme Is Ruby alive? (Should print every 0.1s) . [HICCUP -- VM was probably blocked for 1.9009780909999998s!] ["/home/ivo.anjo/tmp-hello-mount-deleteme/"] ``` ...here's how it looks after your PR: ``` $ ./miniruby repro.rb readdir /home/ivo.anjo/tmp-hello-mount-deleteme Is Ruby alive? (Should print every 0.1s) ........................................(Opened!).................... ["hello"] $ ./miniruby repro.rb chdir /home/ivo.anjo/tmp-hello-mount-deleteme Is Ruby alive? (Should print every 0.1s) .................... nil $ ./miniruby repro.rb fchdir /home/ivo.anjo/tmp-hello-mount-deleteme Is Ruby alive? (Should print every 0.1s) ........................................(Opened!).................... nil $ ./miniruby repro.rb chroot /home/ivo.anjo/tmp-hello-mount-deleteme Is Ruby alive? (Should print every 0.1s) .................... #<Errno::EPERM: Operation not permitted @ dir_s_chroot - /home/ivo.anjo/tmp-hello-mount-deleteme> $ ./miniruby repro.rb lstat /home/ivo.anjo/tmp-hello-mount-deleteme Is Ruby alive? (Should print every 0.1s) ................................................................................ ["/home/ivo.anjo/tmp-hello-mount-deleteme/.", "/home/ivo.anjo/tmp-hello-mount-deleteme/hello"] $ ./miniruby repro.rb stat /home/ivo.anjo/tmp-hello-mount-deleteme Is Ruby alive? (Should print every 0.1s) .................... ["/home/ivo.anjo/tmp-hello-mount-deleteme/"] ``` I'm also attaching the "adversarial" FUSE filesystem -- I basically added a bunch of sleeps to https://github.com/libfuse/libfuse/blob/master/example/hello.c (my version attached), built the examples and mounted the filesystem. Hopefully this helps, and thanks again for picking this one up :)) ---------------------------------------- Bug #20587: dir.c calls blocking filesystem APIs/system calls while holding the GVL https://bugs.ruby-lang.org/issues/20587#change-109106 * Author: ivoanjo (Ivo Anjo) * Status: Open * Backport: 3.1: UNKNOWN, 3.2: UNKNOWN, 3.3: UNKNOWN ---------------------------------------- Hey! I work for Datadog on the Ruby profiler part of the [`datadog` (previously `ddtrace`)](https://github.com/datadog/dd-trace-rb) gem. While I was investigating https://bugs.ruby-lang.org/issues/20586, I spotted that there's a number of cases where, in `dir.c`, blocking system calls are being made (e.g. `readdir()`, ~~`opendir()`~~, ... see comments for more detailed list...) without releasing the GVL. This means that if they block for a long time (as happens in the gcsfuse example in https://bugs.ruby-lang.org/issues/20586 ), the Ruby VM will just be blocked and not make any progress. The combination of not releasing the GVL + slow system calls actually makes the issue in https://bugs.ruby-lang.org/issues/20586 more likely to happen with the Datadog profiler, although even if the code releases the GVL the underlying issue could still happen, and this is why I decided to file this bug separately. ---Files-------------------------------- repro.rb (1.18 KB) hello.c (4.89 KB) -- https://bugs.ruby-lang.org/

Issue #20587 has been updated by jeremyevans0 (Jeremy Evans). I submitted https://github.com/ruby/ruby/pull/11176 for the `getattrlist` and `fgetattrlist` changes. ---------------------------------------- Bug #20587: dir.c calls blocking filesystem APIs/system calls while holding the GVL https://bugs.ruby-lang.org/issues/20587#change-109147 * Author: ivoanjo (Ivo Anjo) * Status: Open * Backport: 3.1: UNKNOWN, 3.2: UNKNOWN, 3.3: UNKNOWN ---------------------------------------- Hey! I work for Datadog on the Ruby profiler part of the [`datadog` (previously `ddtrace`)](https://github.com/datadog/dd-trace-rb) gem. While I was investigating https://bugs.ruby-lang.org/issues/20586, I spotted that there's a number of cases where, in `dir.c`, blocking system calls are being made (e.g. `readdir()`, ~~`opendir()`~~, ... see comments for more detailed list...) without releasing the GVL. This means that if they block for a long time (as happens in the gcsfuse example in https://bugs.ruby-lang.org/issues/20586 ), the Ruby VM will just be blocked and not make any progress. The combination of not releasing the GVL + slow system calls actually makes the issue in https://bugs.ruby-lang.org/issues/20586 more likely to happen with the Datadog profiler, although even if the code releases the GVL the underlying issue could still happen, and this is why I decided to file this bug separately. ---Files-------------------------------- repro.rb (1.18 KB) hello.c (4.89 KB) -- https://bugs.ruby-lang.org/