SNSピリカのサービスでは、データ永続化用にCloud NDBを使用しています。また、データ取得のスループットを高めるためCloud Memorystore for Redisを利用しています。

そこで、用途毎でnamespace切り分けるためにredis-namespaceライブラリを使っていました。しかしながら、Cloud NDBで特定のエンティティ間でキャッシュキーが重複してしまい、別エンティティのキャッシュが保存・読み込みされてしまうことがありました。例えばID:1のエンティティを参照したときにID:2のエンティティを参照していました。

　TL;DR

redis-namespaceライブラリは使用せず、redisのキャッシュ操作をする前段にて自身でnamespaceを付けるようにしましょう。例えば、redisのラッパークラスにて、初期化時にサービスに対するnamespaceを渡しておき、get, set, get_dict...等のラッパー関数呼び出し時にキー名と結合します。

これにより、キャッシュアクセス時は透過的にキャッシュを操作することができ、なおかつ用途毎にnamespaceを分けることができます。

def namespaced_key(key: str, namespace: str, service_namespace: str) -> str:
    return "{0}:{1}:{2}".format(service_namespace, namespace, key)


# Cacheはget, set, incr, ... など、redisのメソッドを呼び出すためのインタフェース定義
class RedisCache(Cache):
    def __init__(self, redis: StrictRedis, service_namespace: str):
        # service_namespace: サービス単位で付与するnamespace
        self.service_namespace = service_namespace
        self.redis = redis

    def get(self, key: str, namespace: str) -> CacheValue:
        ns_key = namespaced_key(key, namespace, self.service_namespace)
        return self.redis.get(ns_key)

    ...

発生した現象

認証APIをCloud NDB(google-cloud-ndbライブラリ)を使って移植していました。ログイン機能が揃ったので、アプリからログインをしてみました。1アカウントのみログインしたときは特に問題ありませんでしたが、2アカウント分ログインすると1つ目のアカウントで全ての要認証APIで403エラーとなりました。

サーバログを見る限り、以下のことがわかりました。

ログイン処理は出来ており、セッション情報は生成されていました。
ローカル環境でもクラウド環境でも同様に発生しました。
セッション情報を取得するとき、正しいクエリ情報を渡しているのにも関わらず、別のユーザの情報が取得されました。

以上のことより、コード以外の要因と想定しました。そこで、キャッシュの挙動をチェックしましたところ、事前にキャッシュクリアしていると再現しないことがわかりました。また、特定のユーザの組み合わせでのみ再現することがわかりました。

原因

詳しく原因を見るために、エンティティIDとキャッシュキーの対応関係を見てみました。すると、特定のエンティティの組み合わせでキャッシュキーが重複することがわかりました。

OKパターン: いずれも別のキャッシュキーになっている

ID: 6284539898888192
"ndb:NDB30\n\x0b\x12\tProjectName\x12\x17\n\x0cEntityName\x10\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\xc2\x97\xef\xbf\xbd\xef\xbf\xbd\x0b"

ID: 1038
"ndb:NDB30\n\x0b\x12\tProjectName\x12\x11\n\x0cEntityName\x10\xef\xbf\xbd\b"

ID: 5739254122545152
"ndb:NDB30\n\x0b\x12\tProjectName\x12\x17\n\x0cEntityName\x10\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\xda\xa3\xef\xbf\xbd\xef\xbf\xbd\n"

NGパターン: どちらも同じキーになっている

ID: 5761297639538688
"ndb:NDB30\n\x0b\x12\tProjectName\x12\x17\n\x0cEntityName\x10\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\n"

ID: 5704016969334784
"ndb:NDB30\n\x0b\x12\tProjectName\x12\x17\n\x0cEntityName\x10\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\n"

redis-namespaceライブラリでは、redisのキャッシュキーを作るときにnamespaceを付与します。このとき、指定されたkeyがbytes型だとredisライブラリのnativestrメソッドを使います。Cloud NDB側で生成されるキャッシュ用キーはbytes型なので同メソッドが使われ、UTF-8でデコードされます。しかしながら、変換できない値が入っているとU+FFFD'\xef\xbf\xbd'に変換されてしまいます。

以上の仕組みにより、特定のエンティティ同士でキャッシュキーが同じになってしまい、キャッシュが不整合を起こしていました。

暫定対策

最初発覚したときは、Cloud NDBを使ったサーバ自体がほぼ新規で移植途中だったこともあり、事前にbytes型のキャッシュキーをbase64に変換する方式を取っていました。これにより、UTF-8でデコードできない値がなくなるので、この問題を解消することができました。

約1年強ほど経ち、google-cloud-ndbのバージョンをアップデートすることになりました。しかしながら、base64に変換する処理とredisのインタフェース変更で不整合が発生し、ローカル開発中のサーバが動かない状況となりました。

恒久対策

上記原因を改めて開発チーム内で確認し、対策を検討しました。そこで、AppEngineのアプリ内でnamespaceを注入するように方針変換しました。この方式であれば、ndb.RedisCacheのインタフェースの変更の影響を受けないので、暫定対策で発生した問題は起きなくなります。また、この変更に伴い、redis-namespaceを廃止しました。同ライブラリは最終更新からすでに3年ほど経っており、更新の見込みがなかったためです。

振り返ってみて

昨年6月の時点で、Pull Requestで本現象は共有されていました。しかしながら、UTF-8への変換タイミングが明記できておらず、サーバのどの部分が本現象を発生させているか不明瞭でした。ここでredis-namespaceのadd_namepsaceメソッドでUTF-8に変換されていること、また同メソッドを使わなければ同現象が発生しないことが伝達できていれば、昨年6月の段階で恒久対策が打てていた可能性があります。

以下、当該PRより引用

## 問題の発生原因
DatastoreのEntityについて、ndbライブラリではRedisにキャッシュするとき以下のkeyの形式になっています。

`NDB30\n\x0b\x12\tProjectName\x12\x17\n\x0cEntityName\x10\x80\x80\x80\x8a\xdf\xf8\x90\n`

`NDB30\n\x0b\x12\tProjectName\x12\x17\n\x0cEntityName\x10\x80\x80\x80\x9a\xea\xfb\x9d\n`

Redisはデフォルトでutf-8でキャッシュを格納します。その関係で、これらのkeyのうち、utf-8に変換できない部分がU+FFFD(\xef\xbf\xbd)に置き換えられます。

`NDB30\n\x0b\x12\tProjectName\x12\x17\n\x0cEntityName\x10\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\n`

`NDB30\n\x0b\x12\tProjectName\x12\x17\n\x0cEntityName\x10\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\xef\xbf\xbd\n`

その結果、keyの内容によっては同じkeyになってしまい、キャッシュ読み出し時に別のデータを読み出してしまうことがありました。

以上になります。ご覧いただきありがとうございます！