Bug #22187: High major GCs caused by specific concurrent workloads in 3.4

• Status: Open
• Assignee: -
• Target version: -
• ruby -v: 3.4.10
• Backport: 3.3: UNKNOWN, 3.4: UNKNOWN, 4.0: UNKNOWN

[rpeng (Richard Peng)]

Hello,

We are running into an issue that's very similar to https://bugs.ruby-lang.org/issues/21838, and believe it has the same root cause of global allocatable slots by running thru git-bisect (https://bugs.ruby-lang.org/projects/ruby-master/repository/git/revisions/079ef92b5e59b616d670efe81a33e500f2bf6451).

For very specific workloads (high concurrency, large-ish file downloads), we are seeing that the amount of major GCs has markedly increased under 3.4. It has occurred in our production workloads and lead to increased tail latencies (almost doubling our p75 / p99s).

To reproduce:

1. Save the reproduction script below to a ruby file repro.rb
2. Run it against official ruby images (3.3.11-trixie, and 3.4.10-trixie)
3. See the differences in major GC count

docker run --rm --pull always -v "$PWD/repro.rb:/repro.rb:ro" ruby:3.3.11-trixie ruby /repro.rb
# output: [3.3.11] threads=9 total=2000 body=4MB  majors=8  minors=771

docker run --rm --pull always -v "$PWD/repro.rb:/repro.rb:ro" ruby:3.4.10-trixie ruby /repro.rb
# output: [3.4.10] threads=9 total=2000 body=4MB  majors=56  minors=752

Reproduction script:

# repro.rb
require "socket"
require "net/http"

THREADS = 9
ITERATIONS = 2000
ITERATIONS_PER_THREAD = ITERATIONS / THREADS
BODY_MB = 4
BODY = 'x' * (BODY_MB * 1024 * 1024)

srv  = TCPServer.new("127.0.0.1", 0)
PORT = srv.addr[1]

Thread.new do
  loop do
    begin
      conn = srv.accept
    rescue StandardError
      break
    end

    Thread.new(conn) do |c|
      begin
        loop do
          received_line = false

          while (line = c.gets)
            received_line = true
            break if line == "\r\n"
          end

          break unless received_line

          c.write "HTTP/1.1 200 OK\r\nContent-Length: #{BODY.bytesize}\r\n" \
                    "Connection: keep-alive\r\n\r\n"
          c.write BODY
        end
      ensure
        c.close
      end
    end
  end
end

def download
  Net::HTTP.get("127.0.0.1", "/", PORT).bytesize
end

# warm up the heap to steady state, then measure only the download loop.
2.times { Array.new(THREADS) { Thread.new { 2.times { download } } }.each(&:join) }
Process.warmup

before = GC.stat
Array.new(THREADS) { Thread.new { ITERATIONS_PER_THREAD.times { download } } }.each(&:join)
after = GC.stat

puts format("[%s] threads=%d total=%d body=%dMB  majors=%d  minors=%d",
            RUBY_VERSION, THREADS, ITERATIONS, BODY_MB,
            after[:major_gc_count] - before[:major_gc_count],
            after[:minor_gc_count] - before[:minor_gc_count])

srv.close

We suspect that this line change here: https://github.com/ruby/ruby/pull/11562/changes#diff-d23f31a61dfe958dc753964bcf47cc297d97cf0540811b97b7a27f4ca575e8b5L4040 is causing more aggressive major GCs when the heap should be growing instead, but I am admittedly not well versed in Ruby core code. We made an experiment to add back the check (total_slots < init_slots) in gc/default.c, and it seemed to have remediated the issue, but I'm not sure what trade offs comes with that change.