GAミント至上主義

Web Monomaniacal Developer.

Pythonで作ったプロセスのメモリ肥大化の原因調査から解決まで

2017/9/25 追記変更

公式ライブラリの大幅アップデートがあり、0.28.3ではメモリリークがなくなったが別の問題が発生し、嫌になったので、Cloud Pub/Subでのsubscribe処理はあきらめRedis Pub/Subに戻した

pypi.python.org

uyamazak.hatenablog.com

元記事

Dockerで作っているoceanusでは、WEBサーバーだけでなく、Pythonで書いた常時稼働プロセスのコンテナが複数ある。

GitHub - uyamazak/oceanus: Send big data to Google BigQuery and redis pub/sub using HTTP beacons simply

r2bq

Redis to BigQueryの略。名前の通り、Redisのリストから取り出して、BigQueryに書き込む

table-manager

必要なBigQueryのテーブルがあるか確認して、無ければ作成する


どちらも、Dockerの1コンテナ1プロセスに乗っ取って分けたもので、コードも短くシンプルなのにメモリ使用量が肥大化してしまう問題があった。

起動直後は40~50MB、数日立つと100MBを超えてしまうこともあった。


GKE上で動かしているコンテナ(pod)ごとのメモリは下記コマンドで簡単に取得できる。

% kubectl top pod
NAME                             CPU(cores)   MEMORY(bytes)
r2bq-1477107478-n1eia            22m          61Mi
table-manager-1307035889-bco9o   13m          78Mi


最初はWhile無限ループの最後でdelだけしてみたけど変わらない。

その後、検索して見つけたgc.collect()を追加した。

gcは標準モジュールなのでインストールは必要ない。

import gc
while keep_processing:

    for site in OCEANUS_SITES:
        r2bq = redis2bqSerial(site)
        try:
            r2bq.main()
        except TimeoutError:
            logger.critical("timeout error exit")
            r2bq.clean_up()

        del site
        del r2bq
        gc.collect()
    sleep(SERIAL_INTERVAL_SECOND)

これを追加しただけで、劇的にメモリ使用量が減った。

% kc top pod  
NAME                             CPU(cores)   MEMORY(bytes)
r2bq-1043652369-7smpb            40m          16Mi
table-manager-1386334450-0x09y   55m          17Mi

どちらも40MB以上から17MB程度と半分以上の削減効果があった。まだ起動して時間が立ってないので持続的な効果はしばらく様子見だけど、これだけでも価値があると思う。

単純にメモリだけで考えれば、同じインスタンスで2倍のコンテナを起動できるようになる。実際はCPUの方が足りなくなる場合がほとんどだけど。

While Trueなどの無限ループを使ったプログラムは、Dockerを使う前はcronでなんとかしていたので書いたことがなく、まだまだ初心者。gc.collect()を使わずとも内部の書き方で減らせるところがあるかもしれない。

Debug Hacks -デバッグを極めるテクニック&ツール

Debug Hacks -デバッグを極めるテクニック&ツール

20時間後経過

上記コンテナを起動して20時間程度経ったので、様子を見てみる

% kc top pod
NAME                             CPU(cores)   MEMORY(bytes)
r2bq-1043652369-7smpb            41m          23Mi
table-manager-1466157299-a5h7p   51m          36Mi

起動時から1.5倍以上にメモリ仕様が増えてしまっていた。
やはりコード実行中に何かお漏らししているらしい。
作成したインスタンスごとdelしてるけど、それでも残ってしまうものがあるようだ。

pipでobjgraphをインストールし(Dockerを使っているのでDockerfileに追記して再build)

増加を表示してくれるobjgraph.show_growth()を追加し一旦ローカルのDockerでテストしてみることにした。

import gc
import objgraph
while True:
    for site in OCEANUS_SITES:
        # logger.debug("check:{}".format(site["site_name"]))
        tm = TableManager(site)
        tm.main()
        del tm
        del site
        gc.collect()
    objgraph.show_growth()
    sleep(INTERVAL_SECOND)

起動すると標準出力で下記のように出してくれる。

function                       4364     +4364
dict                           3960     +3960
tuple                          2865     +2865
weakref                        1502     +1502
wrapper_descriptor             1112     +1112
type                            922      +922
method_descriptor               845      +845
builtin_function_or_method      838      +838
getset_descriptor               729      +729
list                            689      +689

しばらくこれで動かしっぱなしにして、どのオブジェクトが増えてるかを確認してみる。

解決編

原因はGoogle公式のBigQueryのモジュールだった。

GitHub - tylertreat/BigQuery-Python: Simple Python client for interacting with Google BigQuery.

残念ながらobjgraphやtracemallocの結果ではわからず、他にもメモリリークしているプロセスがあり、それと共通して使っているライブラリが該当のモジュールだった。

DockerやKubernetes環境でのメモリの確認方法はこちら記事を参照。

get_clientを呼び出す度に、delや、gc.collect()で消せない領域を使ってしまっているのかも。

ループ内では呼び出さず、ループの前に一度だけ作成し、クラスに渡すことで、メモリの使用量の増加や増減がピタッと止まった。

再現できる最小のコードができたら、報告してみようと思う。

bq_client = get_client(json_key_file=JSON_KEY_FILE, readonly=False)
while True:
    for site in OCEANUS_SITES:
        # logger.debug("check:{}".format(site["site_name"]))
        tm = TableManager(site, bq_client)
        tm.main()
        tm = None
        site = None
        del tm
        del site
        gc.collect()
    sleep(INTERVAL_SECOND)