Help us understand the problem. What is going on with this article?

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

More than 5 years have passed since last update.

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ではためしてません。

Why do not you register as a user and use Qiita more conveniently?
  1. We will deliver articles that match you
    By following users and tags, you can catch up information on technical fields that you are interested in as a whole
  2. you can read useful information later efficiently
    By "stocking" the articles you like, you can search right away
Comments
Sign up for free and join this conversation.
If you already have a Qiita account
Why do not you register as a user and use Qiita more conveniently?
You need to log in to use this function. Qiita can be used more conveniently after logging in.
You seem to be reading articles frequently this month. Qiita can be used more conveniently after logging in.
  1. We will deliver articles that match you
    By following users and tags, you can catch up information on technical fields that you are interested in as a whole
  2. you can read useful information later efficiently
    By "stocking" the articles you like, you can search right away