Nokogiri blocking the GVL

[jacobat]

I've been talking to @flavorjones on Slack and he requested that I start a discussion here about our uses of Nokogiri.

We're doing some XML munging as part of regular HTTP requests. And we suspect it's causing some latency issues with Puma as Nokogiri is blocking the entire Ruby runtime for periods of time and so concurrent requests are impacted by the XML munging.

In one example we're loading 300+ XML documents and doing a small manipulation on them and then serializing them back out to XML. Most of our XML documents are in the order of kilobytes with a long tail going into many MBs.

To exemplify the blocking here's a small script:

require 'nokogiri'
require 'benchmark'

string = File.read(ARGV[0])
thread_count = Integer(ARGV[1])
iteration_count = Integer(ARGV[2])

def run_threads(thread_count:, iteration_count:)
  Benchmark.measure do
    threads = thread_count.times.map do
      Thread.new do
        iteration_count.times do
          yield
        end
      end
    end
    threads.each(&:join)
  end
end

done = false

t = Thread.new do
  STDOUT.sync = true
  until done
    STDOUT.print "."
    sleep 0.01
  end
end

pp(run_threads(thread_count:, iteration_count:) do
  Nokogiri::XML(string).to_xml
end)

done = true

t.join

Point it at an XML file (for instance this 1MB xml file) and the results running a single thread for 40 iterations will be something like:

$ ruby thread_test.rb mondial-3.0.xml 1 40
.............#<Benchmark::Tms:0x000000010b2fff10
 @cstime=0.0,
 @cutime=0.0,
 @label="",
 @real=1.527104000095278,
 @stime=0.04299200000000001,
 @total=1.521639,
 @utime=1.478647>

If we instead run 4 thread with 10 iterations:

$ ruby thread_test.rb mondial-3.0.xml 4 10
.....#<Benchmark::Tms:0x000000010966fa58
 @cstime=0.0,
 @cutime=0.0,
 @label="",
 @real=1.559099999954924,
 @stime=0.050557,
 @total=1.559404,
 @utime=1.508847>

In both cases the program only manages to print a small number of dots - so the "dot printer" thread is mostly blocked throughout the program. My interpretation of this result is that Nokogiri is the reason the printer is not printing a dot every 10ms.

I suspect that doing this kind of XML munging as part of a web request is a bad idea, and we're trying to move most of our XML processing offline.

[flavorjones]

@jacobat Thanks for opening this discussion. I was on holiday for the past week and I have to catch up on OSS notifications. I'll respond more thoughtfully as soon as I can!

[flavorjones]

It may be worth taking a look at the discussion at #3281 as well