読者です 読者をやめる 読者になる 読者になる

Bignumの10進文字列化を速くしよう

んー、花粉症がひどいし、ここはぱーっとRubyでも高速化して景気づけしたいですね。

先日の日記RubyとCしか読めないこの日記の読者の皆さんも、アセンブラに親しみが持てるようになったのではないかと思います。せっかくなので、引き続きこの方向で頑張ってみましょう。

さて、3年前、akrさんが一度はマージしながらも断念した、Use 128 bit integer type in Bignumという案件があります。今日はここから始めます。同時期に公開された資料に「プログラミング言語 Ruby に GMP を組み込む」というものがあります。読むとakrさんの思想の一端が垣間見え、それはしばしばRubyの仕様に影響を与えたりしなくもないのですが、それはまた別の話。どうも1000bitあたりの基数変換(2進→10進 文字列化) が遅かったみたいですね。

しかし、冷静になって考えてみましょう。32bitでの計算を64bitで計算して遅くなるはずがありません。どこかに遅くしている犯人がいるに違いない。また、天下のIntel様の誇る21世紀のCPUや、人類の叡智の結晶GCCが悪いはずもないでしょう。つまり、CRubyが悪いに決まっています。容疑者が絞れたので、早速今日もperfを使ってみましょう。

./miniruby -ve'n=Random.new.random_number(2**1000);n.to_s while 1'

などと雑なマイクロベンチマークを回しつつ、sudo perf topで見てみましょう。

 64.53%  miniruby               [.] big2str_2bdigits
 21.09%  miniruby               [.] bigdivrem1
  5.10%  miniruby               [.] big2str_karatsuba
  1.98%  miniruby               [.] bary_addc.constprop.35
  0.82%  miniruby               [.] bigdivrem_restoring
  0.69%  miniruby               [.] power_cache_get_power
  0.60%  libc-2.19.so           [.] _int_free

big2str_2bdigitsが1番のボトルネックみたいですね。詳細を見ます。

  0.04 │ 3c:   movslq 0x10(%rbx),%rdi                                                              ▒
  0.00 │       lea    ruby_digitmap,%r9                                                            ▒
       │       movslq 0x4(%rbx),%rcx                                                               ▒
  0.03 │       nop                                                                                 ▒
  0.10 │ 50:┌─ mov    %rsi,%rax                                                                    ▒
  1.42 │    │  xor    %edx,%edx                                                                    ▒
  0.10 │    │  sub    $0x1,%rdi                                                                    ▒
  0.04 │    │  div    %rcx                                                                         ▒
 58.45 │    │  movzbl (%r9,%rdx,1),%eax                                                            ▒
  6.47 │    │  xor    %edx,%edx                                                                    ▒
       │    │  mov    %al,(%r8,%rdi,1)                                                             ▒
  1.69 │    │  movslq 0x4(%rbx),%rcx                                                               ▒
  0.11 │    │  mov    %rsi,%rax                                                                    ▒
       │    │  div    %rcx                                                                         ▒
 27.79 │    │  mov    %rax,%rsi                                                                    ▒
  0.03 │    │  test   %rdi,%rdi                                                                    ▒
       │    └──jne    50                                                                           ▒
       │       movslq 0x10(%rbx),%rbp                                                              ▒
  0.09 │ 7d:   add    %rbp,0x20(%rbx)                                                              ▒
       │ 81:   mov    0x48(%rsp),%rax                                                              ▒
       │       xor    %fs:0x28,%rax

さて、ここで気付くのは最内ループにdivが2個あることです。Cソースを見ると、

        p = b2s->ptr;
        j = b2s->hbase2_numdigits;
        do {
            p[--j] = ruby_digitmap[num % b2s->base];
            num /= b2s->base;
        } while (j);
        len = b2s->hbase2_numdigits;

となっており、%と/の2回ですね。しかたないね…じゃなくて、待って欲しい。割り算の商と余りは一度に両方出せる。人間でも知ってますね。GCC様が知らないはずがありません。書き方を工夫してみましょう。

        p = b2s->ptr;
        j = b2s->hbase2_numdigits;
        do {
            long idx = num % b2s->base;
            num /= b2s->base;
            p[--j] = ruby_digitmap[idx];
        } while (j);
        len = b2s->hbase2_numdigits;

これならGCCも理解できたようで、無事divが1つになりました。

  4291b0:       48 63 73 04             movslq 0x4(%rbx),%rsi
  4291b4:       31 d2                   xor    %edx,%edx
  4291b6:       48 83 e9 01             sub    $0x1,%rcx
  4291ba:       48 f7 f6                div    %rsi
  4291bd:       41 0f b6 14 10          movzbl (%r8,%rdx,1),%edx
  4291c2:       88 14 0f                mov    %dl,(%rdi,%rcx,1)
  4291c5:       48 85 c9                test   %rcx,%rcx
  4291c8:       75 e6                   jne    4291b0 <big2str_2bdigits+0x50>
  4291ca:       48 63 6b 10             movslq 0x10(%rbx),%rbp
  4291ce:       48 01 6b 20             add    %rbp,0x20(%rbx)
  4291d2:       48 8b 44 24 48          mov    0x48(%rsp),%rax
  4291d7:       64 48 33 04 25 28 00    xor    %fs:0x28,%rax
BEFORE:
%  perf stat ./miniruby -ve'1000000.times{1394009519767279294246510141478471797669978954897613915557413368048327134214313607298484892788729181350733701973860680235136215859195604566916047459319639591913564242295277658139309044846000010192944937354743647901341274278586535726609303298455111458383678266601931358370666199705386621791721556094289.to_s}'
ruby 2.4.0dev (2016-03-14 trunk 54096) [x86_64-linux]

 Performance counter stats for './miniruby -ve1000000.times{1394009519767279294246510141478471797669978954897613915557413368048327134214313607298484892788729181350733701973860680235136215859195604566916047459319639591913564242295277658139309044846000010192944937354743647901341274278586535726609303298455111458383678266601931358370666199705386621791721556094289.to_s}':

       8686.042902 task-clock (msec)         #    0.999 CPUs utilized
               136 context-switches          #    0.016 K/sec
                 2 cpu-migrations            #    0.000 K/sec
              1288 page-faults               #    0.148 K/sec
       25492506980 cycles                    #    2.935 GHz
       13225449435 stalled-cycles-frontend   #   51.88% frontend cycles idle
   <not supported> stalled-cycles-backend
       22023197929 instructions              #    0.86  insns per cycle
                                             #    0.60  stalled cycles per insn
        3213414500 branches                  #  369.951 M/sec
           4716993 branch-misses             #    0.15% of all branches

       8.695071305 seconds time elapsed

AFTER (r54102):
% perf stat ./miniruby -ve'1000000.times{1394009519767279294246510141478471797669978954897613915557413368048327134214313607298484892788729181350733701973860680235136215859195604566916047459319639591913564242295277658139309044846000010192944937354743647901341274278586535726609303298455111458383678266601931358370666199705386621791721556094289.to_s}'
ruby 2.4.0dev (2016-03-14 trunk 54096) [x86_64-linux]

 Performance counter stats for './miniruby -ve1000000.times{1394009519767279294246510141478471797669978954897613915557413368048327134214313607298484892788729181350733701973860680235136215859195604566916047459319639591913564242295277658139309044846000010192944937354743647901341274278586535726609303298455111458383678266601931358370666199705386621791721556094289.to_s}':

       6391.824784 task-clock (msec)         #    0.999 CPUs utilized
               134 context-switches          #    0.021 K/sec
                 3 cpu-migrations            #    0.000 K/sec
              1287 page-faults               #    0.201 K/sec
       18756613064 cycles                    #    2.934 GHz
        9833932236 stalled-cycles-frontend   #   52.43% frontend cycles idle
   <not supported> stalled-cycles-backend
       20548725389 instructions              #    1.10  insns per cycle
                                             #    0.48  stalled cycles per insn
        3212938017 branches                  #  502.664 M/sec
           4574367 branch-misses             #    0.14% of all branches

       6.400175165 seconds time elapsed

はい、簡単でしたね。

当初の予定からはちょっとずれた気もしますが、一パッチできたので今日はこの辺で。