forkした後のtime関連関数が遅い

Rubyのプログラムを
https://github.com/grosser/parallel
で並列化させてCPUを使いきろうと試みたのですが、むしろ遅くなった。

ruby-profしたら、Timeの関数の何かがfork前は速いのにfork後に遅くなっていることがわかった。

def foo(m)
  100000.times do
    t = Time.now
    t.send(m)
  end
end

[:getgm,:getlocal,:to_s,:gmtime,:utc,:dup].each do |m|
  t = Time.now
  foo(m)
  puts "parent: #{m} #{Time.now-t}"

  pid = Process.fork do
    t = Time.now
    foo(m)
    puts "child : #{m} #{Time.now-t}"
  end
  Process.wait(pid)
end

% ruby a.rb
parent: getgm 0.169444
child : getgm 4.888034
parent: getlocal 0.180136
child : getlocal 4.901886
parent: to_s 0.31005
child : to_s 5.122047
parent: gmtime 0.145516
child : gmtime 4.936325
parent: utc 0.145516
child : utc 4.940859
parent: dup 0.104069
child : dup 0.099137

time.cを追ってlocaltimeとtzsetがひどく遅いことがわかりました。
https://github.com/ruby/ruby/blob/trunk/time.c#L829

// gcc a.c && ./a.out
#include <stdio.h>
#include <unistd.h>
#include <sys/time.h>
#include <sys/wait.h>

void foo(char* s)
{
  struct timeval tv1;
  struct timeval tv2;
  gettimeofday(&tv1, NULL);
  for(int i=0; i<10000; i++){
    time_t t;
    tzset();
    t = time(NULL);
    localtime(&t);
  }
  gettimeofday(&tv2, NULL);
  printf("%6s %8ld usec\n", s, (tv2.tv_sec  - tv1.tv_sec)*1000*1000 + tv2.tv_usec - tv1.tv_usec);
}

int main()
{
  pid_t pid;
  tzset();
  printf("tzname=%s\n", tzname[0]);
  pid = fork();
  if(pid!=0){
    printf("parent pid=%d\n", pid);
    foo("parent");
    int status;
    waitpid(pid, &status, 0);
  }else{
    printf("child  pid=%d\n", pid);
    foo("child ");
  }
}

TZをいろいろ変えると速くなることがわかりました。

tkrimac2:~/tmp% ./a.out
tzname=JST
parent pid=18410
child  pid=0
parent     6797 usec
child    447324 usec

tkrimac2:~/tmp% TZ=JST-9 ./a.out
tzname=JST
parent pid=18412
child  pid=0
parent     5599 usec
child      5682 usec

tkrimac2:~/tmp% TZ=UTC+0 ./a.out
tzname=UTC
parent pid=18414
child  pid=0
parent     5714 usec
child      5762 usec

tkrimac2:~/tmp% TZ=JST ./a.out
tzname=UTC
parent pid=18416
child  pid=0
parent     6724 usec
child    335606 usec

tkrimac2:~/tmp% TZ=UTC ./a.out
tzname=UTC
parent pid=18418
child  pid=0
parent     7096 usec
child    297855 usec

Rubyのほうも同じ速さになりました。

% TZ=JST-9 ruby a.rb
parent: getgm 0.144426
child : getgm 0.146893
parent: getlocal 0.145261
child : getlocal 0.148292
parent: to_s 0.257256
child : to_s 0.26556
parent: gmtime 0.117557
child : gmtime 0.127873
parent: utc 0.123133
child : utc 0.121378
parent: dup 0.095217
child : dup 0.098818

TZを設定すればよいということがわかった。

% uname -a
Darwin tkrimac2.local 13.2.0 Darwin Kernel Version 13.2.0: Thu Apr 17 23:03:13 PDT 2014; root:xnu-2422.100.13~1/RELEASE_X86_64 x86_64

Linuxではためしてません。