Bug #20157: Regression in GC.measure_total_time

• Status: Closed
• Assignee: -
• Target version: -
• ruby -v: ruby 3.3.0 (2023-12-25 revision 5124f9ac75) [x86_64-linux]
• Backport: 3.0: DONTNEED, 3.1: DONTNEED, 3.2: DONTNEED, 3.3: DONE

[rianmcguire (Rian McGuire)]

Setting GC.measure_total_time = false is no longer disabling GC time measurement in Ruby 3.3.0.

Reproduction script:

puts RUBY_DESCRIPTION

GC.measure_total_time = false

puts "measure_total_time is now false"
puts "GC.stat(:time) = #{GC.stat(:time)}"
puts "There should be no further clock_gettime syscalls"

# Generate some garbage
Random.new.bytes(100 * 1024 * 1024)
GC.start

puts "GC.stat(:time) = #{GC.stat(:time)}. This should be unchanged from above"

Ruby 3.2.2 (expected behaviour):

$ strace --trace=clock_gettime --signal=none ruby --disable-gems bug.rb    
clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {tv_sec=0, tv_nsec=45735959}) = 0
ruby 3.2.2 (2023-03-30 revision e51014f9c0) [x86_64-linux]
measure_total_time is now false
GC.stat(:time) = 0
There should be no further clock_gettime syscalls
GC.stat(:time) = 0. This should be unchanged from above
+++ exited with 0 +++

Ruby 3.3.0:

$ strace --trace=clock_gettime --signal=none ruby --disable-gems bug.rb    
clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {tv_sec=0, tv_nsec=31784505}) = 0
ruby 3.3.0 (2023-12-25 revision 5124f9ac75) [x86_64-linux]
measure_total_time is now false
GC.stat(:time) = 0
There should be no further clock_gettime syscalls
clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {tv_sec=0, tv_nsec=47132055}) = 0
clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {tv_sec=0, tv_nsec=47576566}) = 0
clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {tv_sec=0, tv_nsec=47586656}) = 0
clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {tv_sec=0, tv_nsec=47852906}) = 0
clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {tv_sec=0, tv_nsec=180726043}) = 0
clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {tv_sec=0, tv_nsec=181242023}) = 0
clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {tv_sec=0, tv_nsec=181248873}) = 0
clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {tv_sec=0, tv_nsec=191276005}) = 0
GC.stat(:time) = 11. This should be unchanged from above
+++ exited with 0 +++

It appears that this was caused by commit https://github.com/ruby/ruby/commit/93ac7405b80cc61930d73da04441fa09af1851e1 -- the test for MEASURE_GC inside in gc_enter_event_measure_p was lost in the refactoring.

[rianmcguire (Rian McGuire)]

I've proposed a fix here: https://github.com/ruby/ruby/pull/9427

[kjtsanaktsidis (KJ Tsanaktsidis)]

• Status changed from Open to Closed
• Backport changed from 3.0: UNKNOWN, 3.1: UNKNOWN, 3.2: UNKNOWN, 3.3: UNKNOWN to 3.0: DONTNEED, 3.1: DONTNEED, 3.2: DONTNEED, 3.3: REQUIRED

PR above has been merged - thank you again.

[kjtsanaktsidis (KJ Tsanaktsidis)]

Backport PR: https://github.com/ruby/ruby/pull/9428

[kjtsanaktsidis (KJ Tsanaktsidis)]

• Status changed from Closed to Open

[jeremyevans0 (Jeremy Evans)]

• Status changed from Open to Closed

[naruse (Yui NARUSE)]

• Backport changed from 3.0: DONTNEED, 3.1: DONTNEED, 3.2: DONTNEED, 3.3: REQUIRED to 3.0: DONTNEED, 3.1: DONTNEED, 3.2: DONTNEED, 3.3: DONE

ruby_3_3 920c17dc94239baae05b513046b27967f11a3569.