Blog
objgraphモジュールを使ってPython(rclpy)のメモリリークを突き止める！
2023/04/25
TechMagicのCTO但馬です。今回は、Pythonでのメモリ関連のトラブル追及についての話題です。
ROS 2(rclpy)のバグ…？
「ROS 2(Humble)のPython(rclpy)でActionサーバを書いて、クライアントから繰り返しActionを呼んでいると、最初は良いのだけどだんだんとActionの反応速度が遅くなってくるんです。ROS 2のバグっぽいのですが…」と、エンジニアO氏。えー、書き方のせいじゃないんですか、と最初はちょっと信じられなかったのですが、確かに、チュートリアル(action_tutorials_py)にある非常に簡単なfibonacciサーバで試してみても、一晩ぐらいActionをずっと呼び続けていると明らかにActionの動作が遅くなってくることが確認できました。
さらに、Actionを呼び続けたときのActionサーバの消費メモリをtopコマンドで監視すると、非常にわずかな増え方ではありますが、消費メモリが増えていっていることも分かりました。いわゆるメモリーリーク(memory leak)が起こっているようです。
Pythonのメモリーリーク
「いやちょっとまって、Pythonは自動でメモリ管理がされるって聞いたよ。メモリーリークは起こらないのではないの？」
そのとおりで、Pythonのオブジェクトは参照カウント方式をとっており、あるオブジェクトを参照している他のデータが無くなれば、自動的にそのオブジェクトが破棄される仕組みになっています。なので、CやC++のようにどこからも参照されないオブジェクトがメモリに残ってしまうことは、すくなくともPython言語だけを使って書いていれば（CythonとかCライブラリを内部で読んだりしていなければ）原理的には起こらないはずです。
ただ、Pythonでもメモリーリーク的なことは起こります。それは単に「プログラマがオブジェクトを消した(消えた)つもりで、実はどこかから参照されててそのまま残ってるのを忘れている」場合です。
たとえば、クラス変数のことは忘れがちじゃないでしょうか？うっかりクラス変数でオブジェクトを参照していると、消えているつもりのオブジェクトが残ってしまいます。
#!/usr/bin/env python3
class Foo:
database = []
def __init__(self, data=None):
# クラス変数に何か入れてどっかで使うとか
if data:
self.database.append(data)
class Bar:
pass
def func():
# fooもbarもローカル変数
bar = Bar()
foo = Foo(bar)
# だからこの時点でメモリが解放されるはずでしょ?
return
if __name__ == '__main__':
func()
func()
func()
foo = Foo()
print(foo.database)
# 実際にはfooのクラス変数にはBarオブジェクトが全部残っている
[<__main__.Bar object at 0x7fca3dd83c10>, <__main__.Bar object at 0x7fca3dcea890>, <__main__.Bar object at 0x7fca3dcea860>]
この単純な例だと見逃すようなことはないですが、ソフトウェアの規模が大きくなってきたり、他の人が書いたモジュールを使い始めると、すべてのオブジェクトの参照個所を把握して追いかけるのはなかなか大変です。
objgraphモジュール
そんな参照関連のトラブルを解析するのに使えるのが、objgraphモジュールです。これは、Python内部のオブジェクトの参照状態、たとえばどんなオブジェクトが何個あるとか、そのオブジェクトがどこから参照されているかといった情報を表示することができるデバッグ用のモジュールです。
これを使って先ほどのROS2のアクションサーバを解析してみました。といっても、Actionサーバー側のコールバック内でobjgraph.show_growth()を追加するだけです。この関数は、前回呼ばれたときから増加したオブジェクトとその数を表示してくれるものです。
検証用プログラム：https://github.com/longjie0723/ros2_demos/tree/bug_suspicion
実行してみると、Actionが呼ばれるたびに、Future, Fibonacci_GetResult_Response, Fibonacci_Resultの3つのオブジェクトが1個ずつ増え続けていることが分かりました。数時間、Actionを呼び続けてると、これらのオブジェクトが数万個、メモリ上に蓄積していました。
次に、objgraphでGetResult_Responseオブジェクトの参照グラフを描いてみました。objgraph.show_chain()を呼び出すだけです。
なんとなくですが、ActionServerクラスの_futuresメンバがこれらのオブジェクトを参照したままであることが見てとれます。
ここまで分かれば、そろそろ開発者への報告の頃合いだと思われました。ROS Answersにこの問題について質問して、さらに、詳しそうな人にTwitterとかで聞いてみることにしました。
ROS Answers: rclpy action server seems slowing down and consuming memory in long term
すると、スーパーハカーの1人がすぐに原因を突き止めて、rclpyのレポジトリにPull Requestを提出してくれました。やはり、_futuresメンバーから参照されたオブジェクトが削除されずに残っていることが原因だったようです。まだマージはされていませんが、検証を経て修正されるはずです。めでたしめでたし。
（4/17更新）rollingにマージされたようです。
まとめ
このように、メモリリーク的な不具合は、すぐに気づかないことが多いです。また、今回は毎回消費メモリが増えていくので比較的簡単でしたが、複雑なプログラムだと再現性が低い場合があり、もっと難しい問題になり得ます。その場合、objgraphなどの適切なツールを活用して、一つ一つ確認しながら追及することが重要です。