へっぽこびんぼう野郎のnewbie日記

けろけーろ(´・ω・`)! #vZkt8fc6J

Django REST FrameworkでModelSerializer.to_representationが遅すぎる場合にやること(雑な調べ方)

APIのレスポンスタイムが2秒以上になってしまっていたので原因を発見するためにプロファイルしていた。

普段はどこが遅いのかを特定するときはline_profilerを使っているのだが、これにじゃっかん限界があって見にくくなっていたので、直接ライブラリのソースを読んで勝手に手を入れることにした。このline_profilerをDjangoで使用する方法についてはそのうち別記するつもり。

rest_frameworkのバージョンは3.3.3(ちょっと古い)

調べ方

rest_framework/fields.pyを直接編集する。

このへんにある、to_representationを触ってみる。ぼくの場合は今回SerializerMethodFieldが遅いことがわかっていたので↓のメソッドを次のように変更した。

    def to_representation(self, value):
        method = getattr(self.parent, self.method_name)
        return method(value)

 ↓

    def to_representation(self, value):
        import pickle, time
        loaded = pickle.load(open('repr.dump', 'rb'))
        parent_name = self.parent.__class__.__name__
        data = loaded.get((parent_name, self.method_name), {'count': 0, 'time': 0})

        start = time.time()
        method = getattr(self.parent, self.method_name)
        v = method(value)
        end = time.time()
        elapsed = end - start
        data['count'] += 1
        data['time'] += elapsed
        loaded[(parent_name, self.method_name)] = data
        pickle.dump(loaded, open('repr.dump', 'wb'))
        return v

こんな感じでプロファイルすると↓のようなデータが取得できる。

>>> import pickle
>>> from pprint import pprint
>>> sorted_data = sorted(pickle.load(open('repr.dump', 'rb')), lambda x: x[1]['time'])
>>> pprint(sorted_data)
[(('HomeReviewSerializer', 'get_type_name'),
  {'count': 1, 'time': 2.6464462280273438e-05}),
 (('HomeReviewSerializer', 'get_type'),
  {'count': 1, 'time': 4.1961669921875e-05}),
 (('OtherFunctionSerializer', 'get_admin_email'),
  {'count': 1, 'time': 5.412101745605469e-05}),
 (('HomePostSerializer', 'get_type_name'),
  {'count': 4, 'time': 8.440017700195312e-05}),
 (('HomePostSerializer', 'get_type'),
  {'count': 4, 'time': 0.00011730194091796875}),
 (('HomePointSerializer', 'get_type'),
  {'count': 4, 'time': 0.00012302398681640625}),
 (('HomePointSerializer', 'get_type_name'),
  {'count': 4, 'time': 0.00015425682067871094}),
 (('HomeCardCommentSerializer', 'get_type'),
  {'count': 6, 'time': 0.00028586387634277344}),
〜〜〜
〜〜〜

遅い箇所がわかって便利。 そのうちやり方を洗練させたらまたアップデートする。

基本的に、APIで返すときにrest_framework.reversereverseを使うと遅くなる印象がある。

1つ使うだけで0.03秒ほど遅くなる感じ。データベースにアクセスしているわけでもないのにこの遅さになるのはあんまり好ましくない。

バージョンをあげたら直るのだろうか……?