VirtualBox 5 で利用可能になった Paravirtualization 機能 kvmclock を使う

Oracle に買収されてからずっと 4.x のまま大きな進化が無いのではないかと心配した時期もありましたが、とうとう VirtualBox 5 が出ましたね。 買収後は vagrant や、最近だと boot2docker などで重要度が大きく増しているので、今後の発展にも期待しています。

さて、 VirtualBox 5 の目玉の新機能といえば Paravirtualization 機能がいろいろな所で表に出てますね。これって何なんでしょう?

一般論を言えば、ホストマシンがハードウェアをエミュレートするのが HVM、ゲストマシンにAPIを提供するのが Paravirtualization (PVM) なので、CPU等の仮想化支援機能を使える場所を除いて一般的には PVM の方が高速化・効率化が可能です。

VirtualBox でも 4.x 時代からNICが virtio に対応していました。ネットワークインターフェイスの種類として virtio を利用すれば、実在するハードウェアのNICエミューレートするために無駄なコストを払う必要がなく、すこし軽くなるはずです。

ということは、 VirtualBox 5 で何か PVM のデバイスが追加されたはずです。(個人的にはブロックデバイスが virtio になって高速化されると嬉しいなと期待していました。) 調べてみたところ、ドキュメントにちゃんと載っていました。

10.4. Paravirtualization providers

KVM: Presents a Linux KVM hypervisor interface which is recognized by Linux kernels starting with version 2.6.25. VirtualBox's implementation currently supports paravirtualized clocks and SMP spinlocks. This provider is recommended for Linux guests.

Paravirtualization Provider に KVM を指定すると、 clock と spinlock の PVM が利用できるようです。

このうち clock については、過去に VirtualBox にマルチコアを割り当てると gettimeofday 等のシステムコールが非常に遅くなるという問題にぶつかったことがあり、最近でもよく EC2 などでマルチスレッドプログラムのベンチマークをするときは clocksource を xen から tsc に変更してるなど、個人的に非常に分かりやすく効果がありそうなので、試してみました。

まず、 Paravirtualization Provider に KVM を指定して (GUI では System > Accelaration にあります) Ubuntu 14.04.2 を起動します。

$ cat /sys/devices/system/clocksource/clocksource0/available_clocksource
kvm-clock tsc acpi_pm
$ cat /sys/devices/system/clocksource/clocksource0/current_clocksource
kvm-clock

kvm-clock が利用可能で、デフォルトで利用されていることが解ります。

次に、以下のプログラムで gettimeofday の速度を計測してみます。

#include <sys/time.h>
#include <stdio.h>

int main()
{
    struct timeval tv;
    for (int i=0; i<1000000; i++) {
        int r = gettimeofday(&tv, 0);
        if (r < 0) {
            perror("gettimeofday");
            return 1;
        }
    }
    return 0;
}
$ gcc -O2 -o t t.c -std=c99
$ time ./t
./t  0.05s user 0.00s system 99% cpu 0.058 total

非常に速いですね。 tsc のように、実際にはシステムコールを発行しないようです。 strace しても gettimeofday は確認できませんでした。

tsc と速度を比較してみます。

$ sudo sh -c "echo tsc > /sys/devices/system/clocksource/clocksource0/current_clocksource"
$ cat /sys/devices/system/clocksource/clocksource0/current_clocksource
tsc
$ time ./t
./t  0.02s user 0.00s system 95% cpu 0.023 total

流石に tsc よりは倍くらい遅いのかな。最後に acpi とも比較してみます。 VirtualBox 4 ではマルチコアだとすごい遅かった覚えがあるのですが、さて。

$ sudo sh -c "echo acpi_pm > /sys/devices/system/clocksource/clocksource0/current_clocksource"
$ cat /sys/devices/system/clocksource/clocksource0/current_clocksource
acpi_pm
$ time ./t
./t  0.00s user 1.64s system 99% cpu 1.645 total

gettimeofday 1回あたり 1.64μs. VirtualBox 4 で計測してなかったので比べられないけど、速くなってるかもしれません。

とはいえ、 kvm-clock と比べて30倍、 tsc と比べて80倍遅いので、 gettimeofday() 等のクロック系システムコールを多用するプログラムを動かす場合は避けたいところです。

クロックソースについてはよく知らないので思い込みですが、tsc がCPUのベースクロック(あるいはそれに類する、同期回路を動かすためのクロック) を利用している分、実時間を計測するには不安定(たぶん1日当たりの誤差は1000円の腕時計の方が小さい)なのに対して、 kvm-clock だと自動的にホスト側の時計に同期してくれることを期待しています。

tsc に比べたら倍くらい遅いと言っても、もともと tsc を使った時の gettimeofday が他のシステムコールに比べてタダ同然だったので、気にせず kvm-clock を使って置けば良さそう。

Python の新しいプロファイラ vmprof が面白い

PyPy 2.6 と同時に、 vmprof という CPython/PyPy 用のプロファイラが登場しました。

私はまだ PyPy では使っていませんが、CPythonのプロジェクトをこれでプロファイル取ってみたらなかなか面白かったので紹介します。

概要

Python にはもともと標準ライブラリとしてプロファイラ (cProfile) が付いてきていますが、これは関数の呼び出しと戻りでコールバック関数を呼び出しつつ実行時間を計測するタイプのプロファイラで、短時間でも正確なプロファイルが取れる反面、オーバーヘッドが大きく、小さい関数をたくさん呼び出す部分がオーバーヘッドでより大きく見えてしまうなどの問題がありました。

これと別の種類のプロファイラとして、定期的にサンプリングして、サンプルが多いところが実行時間も多いハズ、というプロファイラもあります。こちらはある程度の量のサンプルを集めないと正確性にかけるものの、オーバーヘッドが小さく、小さい関数をたくさん呼び出す場合も正確にプロファイルができたり、本番環境のサーバーのプロファイルを取ることができたりします。 Go 言語の pprof もそうですし、 Python では私も昔に sigprofiler というものを作ったことがあります。

vmprof もこのサンプリング型のプロファイラです。 PyPy だときっと JIT の状態が見れるなどの特長があるのでしょうが、私は今のところ CPython で使っています。 CPython 用としてみた場合の vmprof の特長は次のような感じです。

  • Pythonのスタックと同時にCのスタックも保存して、同時に見ることができる
  • Python スタックを取る部分も C で実装されており、 sigprofiler よりずっと軽い

vmprof は Python スタックを取るために、 PyEval_EvalFrameEx をトランポリン関数で置き換えます。 SIGPROF シグナルハンドラでCのスタックを解析するのですが、その際にトランポリン関数を見つけるとその引数である frame オブジェクトを見つけて、 frame オブジェクトから Python のスタックを取ります。

(ちなみに、 CPython 用の部分とそれ以外が綺麗に分かれているので、他のインタプリタ型言語でも関数呼び出しの際に呼ばれる関数をセットしたら vmprof が使えるはずです)

C の関数呼び出しは Python の関数呼び出しよりずっと軽いので、トランポリン関数が1つ挟まるだけならほとんどオーバーヘッドはありません。

vmprof-server

コマンドラインでも簡単な出力を見れますが、 vmprof の本領を発揮するにはビジュアライザである vmprof-server が必要です。 これは Django REST framework とシングルページアプリケーションの組み合わせになっています。

他人に見られてもいいなら デモサイト が利用できますし、見られたくないなら自分で簡単にセットアップすることができます。

$ git checkout git@github.com:vmprof/vmprof-server.git
$ cd vmprof-server
$ pip install -r requirements/base.txt
$ ./manage.py runserver

これを使って、次のようなプログラムのプロファイルを取ってみましょう。

import time

def sum1(n):
    return sum(range(n))

def sum2(n):
    return sum(range(n))

def sum12(n, m):
    z = 0
    for _ in range(1000):
        z += sum1(n) + sum2(m)
    return z

def foo():
    return sum12(10000, 100000)

def bar():
    return sum12(30000, 10000)

def main():
    t0 = time.time()
    while time.time() < t0 + 10:
        foo()
        bar()

if __name__ == '__main__':
    main()
$ python -m vmprof -n --web http://vmprof.baroquesoftware.com/ ex2.py

デモサイト

f:id:methane:20150609223332p:plain

このプログラムで、 sum12() は sum1() と sum2() を呼び出していますが、その呼び出し比率は引数によって変わります。そして foo() と bar() が sum12() を呼び出していますが、引数が違うのでその内訳が違うはずです。

vmprof と vmprof-server は sum12() の中身の内訳をまとめてしまわず、ちゃんとスタックを維持してビジュアライズしてくれるのがわかると思います。

例えば ORM を利用している場合、クエリをコンパイルしてる部分と、オブジェクトをフェッチする部分の重さの比率を見ることで、たくさんオブジェクトをロードしてるから重いのか、複雑なクエリをコンパイルしているから遅いのかを判断することができます。

まだまだ未完成なプロジェクトですが、わかって使えばとても強力なので、使ってみて足りない部分にプルリクエストを送ったりして応援していきましょう。

PyMySQLのメンテナにSQLAlchmey開発者のMike Bayer (@zzzeek)さんが参加しました

このブログでも数回紹介していたとおり、今メジャーな PythonMySQL ドライバ3つのうち2つ (MySQL-python の fork の mysqlclient と PyMySQL) を僕がほぼ単独でメンテナンスしている状況でした。

メンテナンスしているといっても、両方とも MySQL-python との互換性を第一に掲げているので、 Python 3 対応が終わった後はほとんど進化は無くて、淡々とバグの修正を積み重ねては1年に1度以上リリースするという程度です。

実際には Python では PostgreSQL 周りに比べて MySQL 周りは遅れていて幾つか改善案はあったのですが、子育てや他にも Python でやりたい事があったり仕事でも Go で楽しんでたりして手を付けられていませんでした。

そんな状況の中、 Mike さんが PyMySQL-Users ML に突然投稿をされました。 OpenStackの開発でPyMySQLを利用する事を検討していて、問題点・改善点が上がっているんだけど、PyMySQL側にプルリクエストなどを受け入れる準備があるかどうかを質問するものでした。

もともとmysqlclientとPyMySQLも個人でメンテナをするべきでないと思っていましたし、MikeさんはPythonで一番高機能なORMであるSQLAlchemyの開発者、そしてOpenStackといえば今Pythonで最も活発なプロジェクトの1つと呼べる巨大プロジェクトです。このチャンスを逃す手はありません。すぐにGithubのPyMySQL Organization に追加することを提案し、快諾してもらいました。

PyMySQLは性能や非同期対応についてのアイデアがあって、これはまさに OpenStack でも求められているものなので、これからOpenStackコミュニティと協力して進化させていこうと思います。

一方 mysqlclient は、最近 MariaDB が非同期APIを追加した MySQL Connector/C をリリースしているので、それに対応させる手段を検討していたのですが、ビルド時に上手く検出できるのか、PyPyでの速度を上げるために ctypes か cffi を使う別プロジェクトを fork するべきか、その場合 CPython では速度低下するけどどうするか…といった問題があり、メンテナンスコストと両立する解決策が見つかってなかったので、これを機に考えるのをやめることにします。

json.dump() は ensure_ascii=False の方が遅かった

Python の標準ライブラリの json モジュールのエンコード機能には ensure_ascii というオプションがあり、デフォルトでは True です。このオプションが真のときは、非ASCII文字を全て "\uXXXX" の形にエスケープします。

ensure_ascii=True の方が安全ですが、DBにjsonシリアライズしたデータを突っ込むなどの用途ではFalseの方がコンパクトになるし、日本語等を含む場合にエスケープされずに読みやすいので、 ensure_ascii=False を多用していました。

ensure_ascii=False はエスケープ処理が減る分速度も向上すると特に実験もせずに信じていたのですが、社内のプロジェクトで ensure_ascii=True の方が圧倒的に速いという報告を受けて、確認してみたら確かに ensure_ascii=True の方が速かったです。

ソースコードを確認したところ、 ensure_ascii=False の場合はエスケープ処理を正規表現の置換で行う一方、 ensure_ascii=True の場合は _json という speedup モジュールを使って高速に処理していました。

ensure_ascii=False の場合用の speedup 関数を追加するパッチを作って 報告 しておいたので、取り込まれれば Python 3.5 からは同等以上の速度になるはずです。

追記

コミットされました

Issue #23206: Make ``json.dumps(..., ensure_ascii=False)`` as fast as th... · ae9739e · python/cpython · GitHub

Python 3.3 以上で使える Python/C API で文字列アクセスを高速化

試しに英語で Blog を書いてみた のですが、書くので精一杯で結局何が言いたいのか分からない感じになってしまったので今後は日本語 Blog 書いてから英訳しようと思います。

Python 3 は 3.2 まで、文字列を unicode に統一した関係で Python 2.7 に比べて遅くなったりメモリ効率が悪くなったりしてしまっていたのですが、 Python 3.3 で PEP 393 Flexible String Representation が導入されて改善されました。

PEP 393 は Python の内部だけではなく Python/C API にも変更を加えており、内部を理解しつつ新しい API を適切に使えば、バイト列と文字列の間の変換を行うような C 拡張を高速化することができます。 そろそろ Python 3.2 のサポートを切れる時期なので、思い当たる人は目を通しておきましょう

PEP 393 の概要

PEP 393 では文字列オブジェクトの内部表現が幾つかに分かれています。

Compact (非 ASCII)

Compact は一番基本的な unicode オブジェクトです。

+--------+--------+------+-------+------+-------------+------+-------------+------+
| Header | length | hash | state | wstr | utf8_length | utf8 | wstr_length | DATA |
+--------+--------+------+-------+------+-------------+------+-------------+------+

Header:      Python オブジェクト共通のヘッダ
length:      文字列長 (codepoint数)
state:       各種フラグ
hash:        ハッシュ値キャッシュ
wstr:        wchar_t* 表現のキャッシュ
utf8_length: utf-8 にエンコードした時のバイト長
utf8:        utf-8 表現のキャッシュ
wstr_length: wstr の長さ
DATA:        NUL 終端したコードポイント列

DATA 内の各 codepoint を何バイトで表現するかは、その文字列が含む最大の codepoint によって 1byte, 2byte, 4byte のどれかが切り替わります。 これを kind と呼んで、 state で管理しています。 例えば文字列の codepoint が 0~255 の範囲に収まる場合、 1BYTE_KIND となり、DATA の大きさは NUL 終端を含めて文字列長+1 byte になります。

wstr と utf8 は、それぞれエンコードした結果のキャッシュです。 これは PyUnicode_AsUTF8() などの API を呼び出した時に生成されます。例えば utf8 は次のようなコードで生成されています:

    if (PyUnicode_UTF8(unicode) == NULL) {
        assert(!PyUnicode_IS_COMPACT_ASCII(unicode));
        bytes = _PyUnicode_AsUTF8String(unicode, "strict");
        if (bytes == NULL)
            return NULL;
        _PyUnicode_UTF8(unicode) = PyObject_MALLOC(PyBytes_GET_SIZE(bytes) + 1);
        if (_PyUnicode_UTF8(unicode) == NULL) {
            PyErr_NoMemory();
            Py_DECREF(bytes);
            return NULL;
        }
        _PyUnicode_UTF8_LENGTH(unicode) = PyBytes_GET_SIZE(bytes);
        Py_MEMCPY(_PyUnicode_UTF8(unicode),
        PyBytes_AS_STRING(bytes),
        _PyUnicode_UTF8_LENGTH(unicode) + 1);
        Py_DECREF(bytes);
    }

    if (psize)
        *psize = PyUnicode_UTF8_LENGTH(unicode);
    return PyUnicode_UTF8(unicode);

このコードを読めば分かるように、一旦 PyUnicode_AsUTF8String()utf-8エンコードした bytes オブジェクトを作ってから、その中身を malloc して確保した領域に memcpy しています。 繰り返し利用される場合以外は PyUnicode_AsUTF8String() を使って自前で bytes オブジェクトの中を見たほうが速くて省メモリです。

Compact ASCII

文字列に含まれる文字が ASCII である場合、次のような等式が成り立ちます。

  • utf8_length = length
  • utf8 = DATA
  • wstr_length = length

そのため、 Compact から要らない要素を取り除いた特別な表現を利用します。

+--------+--------+------+-------+------+------+
| Header | length | hash | state | wstr | DATA |
+--------+--------+------+-------+------+------+

utf8 キャッシュが存在せず、 PyUnicode_AsUTF8()PyUnicode_AsUTF8AndSize() は直接 DATA を返すので常に高速です。

Legacy

PEP 393 によって deprecated になった API のために用意された、古い構造です。 PyUnicode_Ready() で Compact 形式にインプレイス変換できます。

事例1: UltiraJSON

UltraJSON は高速な JSON エンコーダ/デコーダです。

典型的な JSON は多くの ASCII 文字列を含みます。 そして Compact ASCII 表現の場合、 utf8 へのエンコードをスキップすることができます。 それ以外の場合は、 PyUnicode_AsUTF8String() を使って bytes 型に変換してやります。

# https://github.com/esnme/ultrajson/pull/159
diff --git a/python/objToJSON.c b/python/objToJSON.c
index e56aa9b..a5b2f62 100644
--- a/python/objToJSON.c
+++ b/python/objToJSON.c
@@ -145,7 +145,17 @@ static void *PyStringToUTF8(JSOBJ _obj, JSONTypeContext *tc, void *outValue, siz
static void *PyUnicodeToUTF8(JSOBJ _obj, JSONTypeContext *tc, void *outValue, size_t *_outLen)
{
   PyObject *obj = (PyObject *) _obj;
-  PyObject *newObj = PyUnicode_EncodeUTF8 (PyUnicode_AS_UNICODE(obj), PyUnicode_GET_SIZE(obj), NULL);
+  PyObject *newObj;
+#if (PY_VERSION_HEX >= 0x03030000)
+  if(PyUnicode_IS_COMPACT_ASCII(obj))
+  {
+    Py_ssize_t len;
+    char *data = PyUnicode_AsUTF8AndSize(obj, &len);
+    *_outLen = len;
+    return data;
+  }
+#endif
+  newObj = PyUnicode_AsUTF8String(obj);
   if(!newObj)
   {
     return NULL;

このパッチの効果をマイクロベンチマークで確認してみます:

$ # Before
$ python3.4 -m timeit -n 10000 -s 'import ujson; x = ["a"*10]*100' 'ujson.dumps(x)'
10000 loops, best of 3: 15.8 usec per loop

$ # After
$ python3.4 -m timeit -n 10000 -s 'import ujson; x = ["a"*10]*100' 'ujson.dumps(x)'
10000 loops, best of 3: 7.14 usec per loop

事例2: Meinheld

Meinheld は高速な WSGI サーバーです。

HTTPヘッダのフィールド名は RFC で ASCII 文字列だと定義されていて、フィールド値はバイト列ですが PEP 3333 で latin-1 として扱うと定義されています。

HTTP ヘッダを作る場合は、 "HTTP_ACCEPT_ENCODING" のような文字列を作る必要があります。 受信バッファには "accept-encoding" のような文字列が入っているので、インプレイスで大文字化と - から _ への変換を行っても、 HTTP_ をつけることができません。 この場合、 PyUnicode_New(length, maxchar) の第二引数に 127 を与えると Compact ASCII 形式の空の unicode オブジェクトを作ってくれるので、 そこに対して直接文字列を書き込む事で "HTTP_" をつけるためだけに受信バッファと別に中間バッファを挟む必要がありません。

一方 HTTP フィールド値の方は "HTTP_" のような prefix をつけたりしないので、 PyUnicode_New() を使わなくても直接受信バッファから unicode を生成できます。 PyUnicode_DecodeLatin1() を使えば、実際に受信バッファに ASCII 外の文字があるかどうかによって自動的に Compact ASCII か Compact かを選んで生成してくれます。

逆に unicode から HTTP ヘッダを生成する場合も、unicode が ASCII か Latin-1 でない場合はエラーにできるので、 DATA 部分を直接 writev(2) に渡すことができます。

static int
wsgi_to_bytes(PyObject *value, char **data, Py_ssize_t *len)
{
#ifdef PY3
    if (!PyUnicode_Check(value)) {
        PyErr_Format(PyExc_TypeError, "expected unicode object, value "
        "of type %.200s found", value->ob_type->tp_name);
        return -1;
    }
    if (PyUnicode_READY(value) == -1) {
        return -1;
    }
    if (PyUnicode_KIND(value) != PyUnicode_1BYTE_KIND) {
        PyErr_SetString(PyExc_ValueError,
        "unicode object contains non latin-1 characters");
        return -1;
    }
    *len = PyUnicode_GET_SIZE(value);
    *data = (char*)PyUnicode_1BYTE_DATA(value);
    return 0;
#else
    return PyBytes_AsStringAndSize(value, data, len);
#endif
}

meinheld の主に http ヘッダ生成側を最適化してベンチマークしたところ、だいたい 23.5k req/sec から 25k req/sec へパフォーマンスが向上しました。

ちなみに前回 picohttpparser の比較で Python 2.7 を利用したのは、ヘッダパース部分をリライトするときに新APIを使ってしまったため、 Python 3 では純粋に HTTP パーサーの性能差を見ることができなかったためです。 今回は逆に picohttpparser 化前のソースコードを最適化したので、ヘッダパース側の最適化は手を抜いています。完全に最適化したらもう少し差が広がると思います。

最適化前:

$ ./wrk http://localhost:8000/
Running 10s test @ http://localhost:8000/
  2 threads and 10 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   385.68us   25.67us 843.00us   74.12%
    Req/Sec    12.42k   632.30    13.78k    59.64%
  234475 requests in 10.00s, 39.13MB read
Requests/sec:  23448.18
Transfer/sec:      3.91MB
$ ./wrk http://localhost:8000/
Running 10s test @ http://localhost:8000/
  2 threads and 10 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   379.78us   24.96us   0.90ms   73.86%
    Req/Sec    12.46k   639.91    14.00k    52.45%
  235688 requests in 10.00s, 39.33MB read
Requests/sec:  23569.38
Transfer/sec:      3.93MB
$ ./wrk http://localhost:8000/
Running 10s test @ http://localhost:8000/
  2 threads and 10 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   388.15us   24.65us 524.00us   73.31%
    Req/Sec    12.43k   623.66    13.78k    55.26%
  234899 requests in 10.00s, 39.20MB read
Requests/sec:  23490.25
Transfer/sec:      3.92MB

最適化後:

$ ./wrk http://localhost:8000/
Running 10s test @ http://localhost:8000/
  2 threads and 10 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   339.98us   65.87us   4.33ms   92.45%
    Req/Sec    13.56k     1.43k   15.44k    81.82%
  253189 requests in 10.00s, 42.26MB read
Requests/sec:  25319.67
Transfer/sec:      4.23MB
$ ./wrk http://localhost:8000/
Running 10s test @ http://localhost:8000/
  2 threads and 10 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   364.82us   78.85us   1.01ms   84.10%
    Req/Sec    12.99k     1.81k   15.44k    80.63%
  243685 requests in 10.00s, 40.67MB read
Requests/sec:  24368.90
Transfer/sec:      4.07MB
$ ./wrk http://localhost:8000/
Running 10s test @ http://localhost:8000/
  2 threads and 10 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   329.00us   22.40us 464.00us   73.99%
    Req/Sec    13.66k   760.36    15.44k    61.95%
  258730 requests in 10.00s, 43.18MB read
Requests/sec:  25873.60
Transfer/sec:      4.32MB
このブログに乗せているコードは引用を除き CC0 1.0 で提供します。