Perl6と多言語の起動時間の比較(Perl5,Ruby,Python,Java,Perl6 on MoarVM,Perl6 on JVM)

Ruby Python Perl6 Perl Java

追記(2018/07/19)

処理速度ではなくてプログラムの起動時間というご指摘を受けたのでタイトルを修正しました🙏🙏 純粋な処理時間の測定は別途行おうと思います．後半の感想の部分は読み流して頂けると 🙇 🙇

目的

今回は以前のエントリで書いたようなPerl6の正規表現などを使い同じ処理をするプログラムが，各言語でどういったパフォーマンスの差が出るかの検証を行います．

題材

題材としてはmac os Xの /var/log/system.logのデーモンの回数を数え上げるというプログラムです． 処理の流れとしてはまずコマンドライン引数を確認し，それに応じてファイルを開きます． 開くことが想定されている/var/log/system.logファイルは次のような形式になっています．

Jul 18 01:31:55 anatofuzMBP Dropbox[96084]: [0718/013155:WARNING:dns_config_service_posix.cc(306)] Failed to read DnsCo>
Jul 18 16:57:52 anatofuz-15 idea[66753]: BUG in libdispatch client: kevent[mach_recv] monitored resource vanished befor>

ここから正規表現でデーモンの名前をキャプチャし，一度連想配列を利用してそれぞれのデーモンの出現回数を数え上げます． 最終的に連想配列のkeyをfor文でループさせながら，それぞれの合計を計算するという流れです．

実験

今回はPerl6(MoarVM)とPerl6(JVM)の速度比較を中心に行いました． 解説するとPerl6はベースとなるVMが現在MoarVMかJVMか選択出来るようになっている為，この２つの速度差を図ります． またライバルとなるRuby,Python,Perl5らスクリプト言語や，JVM自体の速度の測定のためにjavaでも実験しました．

  • perl v5.26.2
  • ruby 2.5.1p57 (2018-03-29 revision 63029) [x86_64-darwin17]
  • Python 3.7.0
  • java 10.0.1 2018-04-17
  • Rakudo version 2018.04.1 built on MoarVM version 2018.04.1 (debugオプション付き)
  • Rakudo Star version 2018.04.1 built on MoarVM version 2018.04.1
  • Rakudo version 2018.06-163-g612d071b8 built on JVM

実験コード

今回使用したコードは次のリポジトリのpushしています．

github.com

Members/anatofuz/Perl6_log_analyze_example: 4f7103163762 /

書き方をある程度統一し，純粋な言語機能の測定を行います．

Perl5

#!/usr/bin/env perl
use strict;
use warnings;

my $file = "/var/log/system.log";

if(@ARGV == 2){
    if ( $ARGV[0] eq "-f"){
        $file = $ARGV[1];
    }
}

my $user_name = qr/anatofuzMBP|anatofuz-15/;
open my $fh, "<",$file;
my $count = {};

while (my $line = <$fh>) {
    if ( $line =~ /\w \d{0,2} (?:\d{2}:?){3} $user_name ([\w.]+)\[\d+\]/){
        $count->{$1}++;
    }
}

my $sum = 0;

for my $key (keys %$count){
    $sum += $count->{$key};
}

print "$sum\n";

素朴にハッシュリファレンスに加算しています

Ruby

#!/usr/bin/env ruby

file = "/var/log/system.log"

user_name = Regexp.new("anatofuzMBP|anatofuz-15")
count = Hash.new(0)

File.open(file,'r') do |f|
    f.each_line do |line|
        if line =~ /\w+ \d{0,2} (?:\d{2}:?){3} #{user_name} ([\w.]+)\[\d+\]/
            count[$1] += 1
        end
    end
end


sum = 0

for key in count.keys
    sum += count[key]
end

p sum

書き方を統一するためにあえて最後はfor文でLoopをさせています． Rubyでforとか数百年ぶりに書いたかも知れない

Python

#!/usr/bin/env python
import re
import sys
from collections import defaultdict

file_path = "/var/log/system.log"
args = sys.argv

if args == 3:
    if args[1] == "-f":
        file_path = args[2]

count = defaultdict(int)

with open(file_path) as f:
    for line in f:
        match = re.search(r'\w+ \d{0,2} (?:\d{2}:?){3} (?:anatofuzMBP|anatofuz-15) ([\w.]+)\[\d+\]',line)
        if match:
            count[match.group(1)]+=1

total = 0

for key in count.keys():
    total +=count[key]

print(total)

Perl6

#!/usr/bin/env perl
use v6;

unit sub MAIN(:f($file) where { .IO.f } = '/var/log/system.log');

my $user_name = /'anatofuzMBP'|'anatofuz-15'/;
my $fh = open $file,:r;
my %count =();

for $fh.lines -> $line {
     if ( $line ~~ /\w+ \s \d**0..3 \s [\d**2\:?]**3 \s $user_name \s (<[\w.]>+)\[\d+\]/) {
         %count{$0}++;
    }
}
$fh.close;
my $sum = 0;

for %count.keys -> $key {
    $sum += %count{$key};
}

$sum.say;

ちなみになんですがPerl6の正規表現はリテラル上の空白を無視する為，明示的に空白があると書かないといけません． また範囲演算子は **をつけるルールとなっています．

java

package com.google.anatofuz;

import java.io.File;
import java.io.FileReader;
import java.io.BufferedReader;
import java.io.FileNotFoundException;
import java.io.IOException;
import java.util.*;
import java.util.regex.Pattern;
import java.util.regex.Matcher;

public class LogAnalyzer {

    public static void main(String args[]) {

        File file = new File("/var/log/system.log");

        if (args.length != 0) {
            if (args[0].equals("-f")) {
                file = new File(args[1]);
            }
        }

        try {
            FileReader filereader = new FileReader(file);
            BufferedReader bufferedReader = new BufferedReader(filereader);

            String line;
            Map<String,Integer>  map = new HashMap<String,Integer>(0);
            Pattern p = Pattern.compile("\\w+ \\d{0,2} (?:\\d{2}:?){3} (?:anatofuzMBP|anatofuz-15) ([\\w.]+)\\[\\d+\\]");


            while ((line = bufferedReader.readLine()) != null) {
                Matcher matcher = p.matcher(line);
                if (matcher.find()) {
                    map.merge(matcher.group(1),1,Integer::sum);
                }
            }

            int sum = 0;

            for (String key :map.keySet()){
                sum += map.get(key);
            }

            System.out.println(sum);


        } catch (FileNotFoundException ex){
            System.out.println(ex);
        } catch (IOException ex){
            System.out.println(ex);
        }
    }
}

なおjavaはbuildツールのgradleを利用してjarに固めています

計測

素朴にzshのtimeを使って計測しました． 簡単な次のようなスクリプトを作成しています．

#!/bin/zsh
#

echo 'perl5'
time perl log_analyze.pl
echo '====='

echo 'ruby'
time ruby log_analyze.rb
echo '====='

echo 'python'
time python log_analyze.py
echo '====='

echo 'java'
time java -jar java/build/libs/anatofuz-1.0-SNAPSHOT.jar
echo '====='

echo 'perl6'
time perl6 log_analyze.p6
echo '====='

echo 'perl6 (debug)'
time /Users/anatofuz/workspace/cr/Basic/build_perl6/bin/perl6 log_analyze.p6
echo '====='

echo 'perl6(jvm)'
cd  /Users/anatofuz/workspace/cr/Basic/jvm/rakudo/
time /Users/anatofuz/workspace/cr/Basic/jvm/rakudo/perl6 /Users/anatofuz/workspace/cr/Basic/perl6/sandbox/log/log_analyze.p6

実行結果

perl5
524
perl log_analyze.pl  0.04s user 0.03s system 84% cpu 0.090 total
=====
ruby
524
ruby log_analyze.rb  0.12s user 0.05s system 81% cpu 0.220 total
=====
python
524
python log_analyze.py  0.06s user 0.05s system 79% cpu 0.137 total
=====
java
524
java -jar java/build/libs/anatofuz-1.0-SNAPSHOT.jar  0.24s user 0.05s system 140% cpu 0.203 total
=====
perl6
524
perl6 log_analyze.p6  0.37s user 0.03s system 137% cpu 0.294 total
=====
perl6 (debug)
524
/Users/anatofuz/workspace/cr/Basic/build_perl6/bin/perl6 log_analyze.p6  0.78s user 0.07s system 112% cpu 0.752 total
=====
perl6(jvm)
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by org.perl6.nqp.runtime.Ops (file:/Users/anatofuz/workspace/cr/Basic/jvm/nqp/install/share/nqp/runtime/nqp-runtime.jar) to field sun.management.RuntimeImpl.jvm
WARNING: Please consider reporting this to the maintainers of org.perl6.nqp.runtime.Ops
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
524
/Users/anatofuz/workspace/cr/Basic/jvm/rakudo/perl6   21.26s user 0.67s system 439% cpu 4.983 total

トップはPerl5で0.04秒です．かなり早いですね． 続いて処理として早いのはPythonです．正規表現などがモジュール化されていましたが高速ですね． Rubyはeach文を使ってないためか0.12と比較的LLの中では低速です．

JavaはPerl5の6倍,Rubyの2倍ですが，JVMが苦手な正規表現を行っているにもかかわらずそこそこの速度が出ています． またこれでJVM自体が遅いわけではない事が分かります．

さてPerl6ですが，MoarVMの場合0.37とPerl5の10倍遅くなっています． debug optionをつけた場合は速度が0.78sとPerl5の19.5倍の速度となっています．1.0s内に収まっていますがやはりちょっと遅いですね．

一番の問題はJVMに乗ったPerl6で，何かしら厳しいエラーがひとしきり出ている上に21.26s掛かっております． 単純計算でPerl5の531.5倍となっています．Javaと比較しても88倍とJVMが悪いわけではないことが分かります．一体どこが原因なんだろう...

感想

やはりなんというかPerl6全体的に遅く，このPerl6を高速化するというのは非常にロマンがある世界かと思われます． 時間はかかりますが，使えないことはないので皆さん試してみたらどうでしょうか．