flatpak に入れた python アプリケーションの起動がやけに遅い
先日 flatpak に python アプリケーションを入れてみたわけだけど、 flatpak をかぶせることによる起動コストの増加はどんなもんだろうか、 と気になったので、 time
を使ってテキトウに計ってみる。
普通に実行した場合:
(venv) $ time konnyaku --help
Usage: konnyaku [OPTIONS] COMMAND [ARGS]...
Options:
--debug / --no-debug
--db-debug / --no-db-debug
--help Show this message and exit.
Commands:
add add site
check check site updates
links list links
list list sites
modify modify site
oneshot add & check but not save
remove remove site
show show site information
konnyaku --help 0.74s user 0.06s system 99% cpu 0.806 total
0.8秒くらい。
続いて flatpak に入れたヤツ:
$ time flatpak run org.u7fa9.konnyaku --help
Usage: konnyaku [OPTIONS] COMMAND [ARGS]...
Options:
--debug / --no-debug
--db-debug / --no-db-debug
--help Show this message and exit.
Commands:
add add site
check check site updates
links list links
list list sites
modify modify site
oneshot add & check but not save
remove remove site
show show site information
flatpak run org.u7fa9.konnyaku --help 0.06s user 0.02s system 2% cpu 2.899 total
2.9秒くらい。
思ってた以上に遅い。何だこれ。
調査
ひとまず python ではなくて、明らかに一瞬で実行が終わるはずのコマンドを実行させてみる:
$ time flatpak run --command=/bin/true org.u7fa9.konnyaku
flatpak run --command=/bin/true org.u7fa9.konnyaku 0.06s user 0.02s system 36% cpu 0.229 total
0.2秒くらい。これが flatpak を立ち上げるのに必要なコスト。じゃあさっきの2秒近い差はどっから出てきた？
python アプリケーションで起動が思いのほか遅いというような場合、 .pyc ファイルを作成し忘れたケースが考えられる。 flatpak では runtime/application は read-only で mount
されるため、パッケージング時に含めそびれると、実行時には作成できない (作成しても保存できない) ので、毎回 .py ファイルを読み込むことになる。
ファイルがあるか確認してみる。
$ flatpak run --command=/bin/sh org.u7fa9.konnyaku
~ $ ls -l /app/lib/python3.5/site-packages/konnyaku/
total 36
-rwxr--r-- 231 nakamuray nakamuray 0 Jan 1 1970 __init__.py
drwxr-xr-x 2 nakamuray nakamuray 8 Jan 1 1970 __pycache__
-rwxr--r-- 2 nakamuray nakamuray 6281 Jan 1 1970 cli.py
-rwxr--r-- 2 nakamuray nakamuray 1599 Jan 1 1970 concurrentutils.py
-rwxr--r-- 2 nakamuray nakamuray 39 Jan 1 1970 exceptions.py
-rwxr--r-- 2 nakamuray nakamuray 3287 Jan 1 1970 models.py
-rwxr--r-- 2 nakamuray nakamuray 3594 Jan 1 1970 tasks.py
~ $ ls -l /app/lib/python3.5/site-packages/konnyaku/__pycache__/
total 31
-rwxr--r-- 2 nakamuray nakamuray 136 Jan 1 1970 __init__.cpython-35.pyc
-rwxr--r-- 2 nakamuray nakamuray 6502 Jan 1 1970 cli.cpython-35.pyc
-rwxr--r-- 2 nakamuray nakamuray 1915 Jan 1 1970 concurrentutils.cpython-35.pyc
-rwxr--r-- 2 nakamuray nakamuray 310 Jan 1 1970 exceptions.cpython-35.pyc
-rwxr--r-- 2 nakamuray nakamuray 3957 Jan 1 1970 models.cpython-35.pyc
-rwxr--r-- 2 nakamuray nakamuray 3004 Jan 1 1970 tasks.cpython-35.pyc
ちゃんとある...が、なんだこのタイムスタンプは？
原因
どうやら flatpak (が内部で使ってる ostree) はファイルの更新日時等々を保存しないらしく、 そのためそこからファイルを取り出すと 1970-01-01 00:00:00 (UTC), unix time で "0" が更新日時として設定されるらしい。
さて、 python は .pyc ファイル中に元のソースファイルの更新日時を保存していて、 これが現在のソースファイルの日時と異なっている場合はファイル内容に変更があると見なし、 .pyc
を読み込まないようになっている。
で、全てのファイルの更新日時が 1970-01-01 00:00:00 に 変更 されてしまったため、 全ての .pyc ファイルでこのチェックに引っかかるようになってしまい、 また先述したように新規で .pyc
ファイルを作成することも出来ないので、 結果として毎回 .py ファイルを読み込むようになってしまっているようだ。
その分が起動時間の差に現れていると考えられる。
対策
.pyc ファイル中に記録されている更新日時情報が 1970-01-01 00:00:00 を指すように、データを書き換える。
この情報は 4-7 bytes の範囲に書かれているようなので、 dd を使ってゼロ埋めしてやればよい。
ということで、前回のパッケージングスクリプトに以下のような変更を加えて作り直す:
diff -r 43abc9291d3b flatpak/build-konnyaku-runtime.bash
--- a/flatpak/build-konnyaku-runtime.bash Mon Feb 20 15:21:54 2017 +0900
+++ b/flatpak/build-konnyaku-runtime.bash Mon Feb 20 21:23:24 2017 +0900
@@ -53,6 +53,10 @@
run_in_rootfs apk update
run_in_rootfs apk add "${RUNTIME_PACKAGES[@]}" || true
+# XXX: fix .pyc's timestamp information to match "1970-01-01 00:00:00",
+# files checked out from ostree will be.
+run_in_rootfs find /usr/lib/python3.5 -name "*.pyc" -exec dd if=/dev/zero of="{}" bs=4 seek=1 count=1 conv=notrunc ";" 2>/dev/null
+
# create sdk based on runtime
cp -a "${rootfs_dir}" "${sdk_dir}"/
diff -r 43abc9291d3b flatpak/build-konnyaku.bash
--- a/flatpak/build-konnyaku.bash Mon Feb 20 15:21:54 2017 +0900
+++ b/flatpak/build-konnyaku.bash Mon Feb 20 21:23:24 2017 +0900
@@ -22,5 +22,10 @@
flatpak build "${build_location}" python3 -m venv /app
flatpak build --share=network "${build_location}" /app/bin/pip install -U pip
flatpak build --share=network "${build_location}" /app/bin/pip install "${URL}"
+
+# XXX: fix .pyc's timestamp information to match "1970-01-01 00:00:00",
+# files checked out from ostree will be.
+flatpak build "${build_location}" find /app -name "*.pyc" -exec dd if=/dev/zero of="{}" bs=4 seek=1 count=1 conv=notrunc ";" 2>/dev/null
+
flatpak build-finish "${BUILD_FINISH_ARGS[@]}" "${build_location}"
flatpak build-export "${REPOSITORY}" "${build_location}" "${VERSION}"
結果
$ time flatpak run org.u7fa9.konnyaku --help
Usage: konnyaku [OPTIONS] COMMAND [ARGS]...
Options:
--debug / --no-debug
--db-debug / --no-db-debug
--help Show this message and exit.
Commands:
add add site
check check site updates
links list links
list list sites
modify modify site
oneshot add & check but not save
remove remove site
show show site information
flatpak run org.u7fa9.konnyaku --help 0.06s user 0.02s system 7% cpu 1.139 total
直接実行した場合の0.8秒と比べて、0.3秒くらいの差。 true を実行した時の0.2秒にかなり近くなった。
余談
flatpak-builder にはコレと同様の対応処理が入っているようなので、 コイツで python アプリケーションが普通にパッケージングできるようになれば、こんなこと気にしなくてよくなるのかも。