Python の datetime.strptime がすんごく遅い件

会社でRADIUSサーバーの認証ログをリアルタイムに解析するツールを作っていたところ、思ったようなパフォーマンスが出ず、line_profiler というプロファイリングツールを使って調べたところ、処理時間の大部分を datetime.strptime で日時の文字列を datetime オブジェクトに変換する一行のコードが占めていました。

strptime だけでスクリプト実行時間の83%を占めている。あきらかにここが原因

そこで、日時の文字列を自分で区切って datetime.datetime() に渡すようにしたところ、処理速度が飛躍的に向上しボトルネックは無くなりました。

下記サンプルコードを使ってベンチマークをしたところ、strptime はなんと4倍以上遅い！(実行環境: macOS Sierra / Python 3.5.2)

from datetime import datetime
import time

logtime_str = '20170101123456'
start = time.time()
for i in range(100000):
    dt = datetime.strptime(logtime_str, '%Y%m%d%H%M%S')
print('strptime: {:.4f}sec, dt:{}'.format(time.time() - start, dt))

# strptime: 2.2368sec, dt:2017-01-01 12:34:56

from datetime import datetime
import time

logtime_str = '20170101123456'
start = time.time()
for i in range(100000):
    dt = datetime(
        year=int(logtime_str[0:4]),
        month=int(logtime_str[4:6]),
        day=int(logtime_str[6:8]),
        hour=int(logtime_str[8:10]),
        minute=int(logtime_str[10:12]),
        second=int(logtime_str[12:14])
    )
print('self parse: {:.4f}sec, dt:{}'.format(time.time() - start, dt))

# self parse: 0.5266sec, dt:2017-01-01 12:34:56

Python 標準のプロファイリングライブラリ cProfile を視覚化する Python Call Graph というツールを使ってみました。

正規表現は使い回しされているようですが、なぜか毎回ロケール情報を取りに行っていて結構な時間がかかっているようです。今回のコードでは使っていませんが、strptime は曜日( 'Monday', '月曜' )なども取り扱えるため、ロケールを解釈する処理が入っているのでしょうか。それにしても時間かかりすぎてません？使い方間違ってるのかな･･･。

テキストのパースは奥が深いことはわかりますが、よく使う標準ライブラリにこのような罠があるというのは少しショックです。。。

---

ほかの言語でも遅い？

(2016/11/8追記) 他の言語はどうなんだろうと思い、力不足ながらも比較してみました

vs Ruby

まずは、意識高い系言語 Ruby。こんなただ ruby の構文に置き換えただけのコード、Rubyist に見られたら八つ裂きにされそうですが、どうか勘弁してください。

miyahan$ ruby -v
ruby 2.3.1p112 (2016-04-26 revision 54768) [x86_64-darwin16]

require 'date'
require 'time'

logtime_str = '20170101123456'
start = Time.now
for i in 0..100000 do
    dt = DateTime.strptime(logtime_str, '%Y%m%d%H%M%S')
end
print('DateTime.parse: ', Time.now - start, 'sec. ')
print('dt: ', dt, "\n")

# DateTime.parse: 0.30088sec. dt: 2017-01-01T12:34:56+00:00

require 'date'
require 'time'

logtime_str = '20170101123456'
start = Time.now
for i in 0..100000 do
    dt = DateTime.new(
        logtime_str[0, 4].to_i,
        logtime_str[4, 2].to_i,
        logtime_str[6, 2].to_i,
        logtime_str[8, 2].to_i,
        logtime_str[10, 2].to_i,
        logtime_str[12, 2].to_i
    )
end
print('DateTime.new: ', Time.now - start, 'sec. ')
print('dt: ', dt, "\n")

# DateTime.new: 0.198785sec. dt: 2017-01-01T12:34:56+00:00

手動パースしたほうが34%ほど高速

vs PHP

次に、私の愛するゆるふわ言語 PHP。久しぶりに書くとドルやらセミコロンやらカッコやら面倒くさい。

miyahan$ php --version
PHP 7.0.12 (cli) (built: Oct 14 2016 09:56:59) ( NTS )
Copyright (c) 1997-2016 The PHP Group
Zend Engine v3.0.0, Copyright (c) 1998-2016 Zend Technologies

<?php
    $logtime_str = '20170101123456';
    $start = microtime(true);
    for ($i=0; $i<100000; $i++) {
        $dt = \DateTime::createFromFormat('YmdHis', $logtime_str);
    }
    print('DateTime:'.number_format(microtime(true) - $start, 5)."sec, ");
    print("dt:".$dt->format('Y-m-d H:i:s')."\n");

    # DateTime:0.21719sec, dt:2017-01-01 12:34:56

<?php
    $logtime_str = '20170101123456';
    $start = microtime(true);
    for ($i=0; $i<100000; $i++) {
        $ts = mktime(
            substr($logtime_str, 8, 2),
            substr($logtime_str, 10, 2),
            substr($logtime_str, 12, 2),
            substr($logtime_str, 4, 2),
            substr($logtime_str, 6, 2),
            substr($logtime_str, 0, 4)
        );
    }
    print('mktime:'.number_format(microtime(true) - $start, 5)."sec, ");
    print("dt:".date('Y-m-d H:i:s', $ts)."\n");

    # mktime:0.18713sec, dt:2017-01-01 12:34:56

<?php
    $logtime_str = '20170101123456';
    $start = microtime(true);
    for ($i=0; $i<100000; $i++) {
        $ts = gmmktime(
            substr($logtime_str, 8, 2),
            substr($logtime_str, 10, 2),
            substr($logtime_str, 12, 2),
            substr($logtime_str, 4, 2),
            substr($logtime_str, 6, 2),
            substr($logtime_str, 0, 4)
        );
    }
    print('gmmktime:'.number_format(microtime(true) - $start, 5)."sec, ");
    print("dt:".date('Y-m-d H:i:s', $ts)."\n");

    # gmmktime:0.14538sec, dt:2017-01-01 12:34:56

手動パースは、モダンな DateTime クラス を使うより33％高速。ただし、GMTと見なして処理する gmmktime() の代わりに、自環境のタイムゾーンを考慮する mktime() を使うと、その差は14%ほどに縮まるので、DateTime クラスを使うことのオーバーヘッドはそこまでないと思います。

まとめ

言語	高級な方法	高速な方法	比
Python 3.5	2.2368s	0.5266s	428%
Ruby 2.3	0.3009s	0.1988s	151%
PHP 7.0	0.2172s	0.1454s	149%

Ruby も PHP も高級な機能を使うことによりで処理時間が50%ほど増えています。ただ一般的なアプリケーションであれば、その柔軟で強力な機能を簡潔なコードで実現できるというメリットに対して、十分ペイできるオーバーヘッドだと思います。一方 Python は428%とちょっと許容できない、というかバグじゃないかと疑うレベルです･･･。

それにしても、Python っておっそいですね･･･。というか PHP 大健闘。