Bug #19461: Time.local performance tanks in forked process (on macOS only?)

• Status: Closed
• Assignee: -
• Target version: -
• Backport: 2.7: UNKNOWN, 3.0: UNKNOWN, 3.1: UNKNOWN, 3.2: UNKNOWN

[ioquatix (Samuel Williams)]

The following program demonstrates a performance regression in forked child processes when invoking Time.local:

require 'benchmark'
require 'time'

def sir_local_alot
  result = Benchmark.measure do
    10_000.times do
      tm = ::Time.local(2023)
    end
  end
  $stderr.puts result
end

sir_local_alot

pid = fork do
  sir_local_alot
end

Process.wait(pid)

On Linux the performance is similar, but on macOS, the performance is over 100x worse on my M1 laptop.

[ioquatix (Samuel Williams)]

• Description updated (diff)

[PvpDJgHP (William Thomas NELSON)]

In Dec 2016, someone investigated a related question and posted here:

https://stackoverflow.com/questions/41353532/41371753#41371753

This person's findings may be helpful.

[ioquatix (Samuel Williams)]

Thanks, that's quite an epic Q/A.

[nobu (Nobuyoshi Nakada)]

• File localtime_test.c localtime_test.c added

Seems unrelated to Ruby.

$ sw_vers 
ProductName:		macOS
ProductVersion:		13.2.1
BuildVersion:		22D68

$ clang localtime_test.c && ./a.out && ./a.out r
Measuring localtime
In parent
  monotonic = 0.002226000
  cputime = 0.001949000
In child
  monotonic = 0.581383000
  cputime = 0.580938000
Measuring localtime_r
In parent
  monotonic = 0.002409000
  cputime = 0.001967000
In child
  monotonic = 0.587200000
  cputime = 0.586385000

[nobu (Nobuyoshi Nakada)]

• File localtime_test.c localtime_test.c added

Rewritten.

$ clang localtime_test.c && ./a.out
Measuring in parent
  localtime_r = 0.002384000
  localtime   = 0.001939000
Measuring in child
  localtime_r = 0.576143000
  localtime   = 0.591077000

[ioquatix (Samuel Williams)]

Wow, it's like 300x slower.

According to the stack overflow discussion, some how this does not affect Python, so maybe it's something about the function we are using in the C standard library. 100% agree it's Darwin's problem but indirectly became Ruby's problem.

[ioquatix (Samuel Williams)]

• File clipboard-202302251716-rh6ma.png clipboard-202302251716-rh6ma.png added

I've submitted a bug report to Apple:

[ioquatix (Samuel Williams)]

• Status changed from Open to Closed

I don't think we can do anything about this, so closing.

[[e-mail] (Lars Vonk)]

Hi, we are running into the same issue when developing so I was wondering if you got any response on the Apple bug report? Or found a workaround?

[catlee (Chris AtLee)]

I ran into this myself, and implemented a workaround here:
https://github.com/ruby/ruby/pull/13968

The idea is to cache our offset from GMT, and then use that in subsequent localtime calculations.
The cache is valid for every second within the same GMT minute.

[ioquatix (Samuel Williams)]

Just for reference, on the lastest macOS, the issue still appears:

% clang localtime_test.c 
% ./a.out 
Measuring localtime
In parent
  monotonic = 0.002930000
  cputime = 0.002454000
In child
  monotonic = 0.553250000
  cputime = 0.552287000

So this is still an issue, in practice.