まえがき
おはこんばんにちは。
株式会AncarのWebエンジニアをしている、unaと申します。
この度は「株式会Ancar ~Advent Calendar 2019~」 8日目を担当させていただきます。
弊社は安心・安全な移動体験を届けるをモットーに
当記事では、そのサービス運用時に発生したWarningの対処を共有させていただきます。
3行まとめ
-
PHP Warning: SessionHandler::read(): Unable to clear session lock recordが3件/日ぐらい発生 - どうやらセッションロック周りが怪しい → n度修正 → 鳴り止まないアラート
- memcachedからredisを移行させた結果、直った（嬉しい
セッションアラートが3件/日
mackerelというサーバー管理システムから、頻繁にアラートがあがるようになった。
内容はPHP Warning: SessionHandler::read(): Unable to clear session lock record
アラートが増加している上に、SEOにも影響が出ている可能性が高まってきたため、対処に動いた。
当時の環境
- PHP7.1
- memcached3.0.3(elasticache)
- nginx/1.10
原因はセッションロックにあり....?
アラート内容でグーグル先生にきいてみたところ、セッションロック周りが怪しいと判明。
セッションデータは、同時書き込みを防ぐためにロックされるため、 ある時点であるセッションの処理ができるスクリプトは、1つだけです。
https://www.php.net/manual/ja/function.session-write-close.php
つまり、セッションロックがかかっている状態で、セッションに再度書き込みをし、エラーとなっていると推測。
また、先のアラートが発生しているのは本番サーバーのみなので、テストサーバーと比較した。
本番サーバー
テストサーバー
はい、ギルティ！！
memcached.sess_lockのタイムがテストサーバーは短い！！
状況証拠は揃えた、いまからガサ入れや！！
意気揚々と/etc/php/7.1/fpm/conf.d/25-memcached.iniの中でsess_lockをテストサーバーと同じタイムに設定。
さらばアラートよ....(と思っていた時期が私にもありました)
結果、アラート発生....
ここから私とアラートの熾烈な戦い(ﾜﾝｻｲﾄﾞｹﾞｰﾑ が始まる。
ロックタイムだけでは不十分.....?
先の戦いでは少し先走りすぎた。
泥臭く地取りを行っていこうぜ と決意し、issueを漁り始めた。
こちらのissueなどを参考に設定をこねた。
session.lazy_write = Off;
memcached.sess_lock_wait_min = 100;
memcached.sess_lock_wait_max = 150;
memcached.sess_lock_retries = 30;
memcached.sess_lock_expire = 45;
しかし、元気よくアラートは鳴っている。
むしろ、少し増えた。
そうか、慈悲はないのか....
issueを漁り始めて気づいたのは、この問題は意外と根深いということ。
先の修正で直るケースもあれば、逆もしかり。
PHP7.1以前とmemcachedの組み合わせで多発しており、PHPのバージョン問題である可能性も高い。
実際にn度目の設定変更を通して、憎きアラートへの対処は適切ではないと痛感している。
有効打と思われるのは下記だ。
- PHP7.2以上
- cf: https://github.com/php-memcached-dev/php-memcached/issues/269#issuecomment-519886598
- redisへ移行
- cf: https://github.com/magento/magento2/issues/5319#issuecomment-265595804
redisへの移行
サービスへの影響を考えるとPHPの更新は、作業・リスクがリターンに見合わんので断念。
結果、redis移行へと路線変更を決意。
同時に、憎むべき対象から宿敵(ﾗｲﾊﾞﾙ へ昇格したアラート氏。
移行の懸念点
- redis移行で問題が本当に解決するのか
- 打ち手: redisにして解決したソースあり
- 打ち手: 本番2号機サーバーで確認
- 移行後にmemcachedに戻れるのか
- 打ち手: エンドポイントをredisに向けて対応（memcachedの設定を上書き）
- 打ち手: テスト環境で双方向(memcached ↔ redis)の行ききをし、後戻りできることを確認
- redis移行で他に問題が起きないのか
- 打ち手: テスト環境で確認
- 打ち手: 本番2号機サーバーで検証
影響範囲が大きいため、打ち手と手順を考えて実行した。
- テスト環境で実装した後、動作確認。
- 本番環境の冗長構成のサーバーを間借りして、動作確認。
- 本番に完全移行。
redis移行の手順
残念ながら、ElastiCache上でMemcachedからRedisへの自動移行はサポートされていない
https://aws.amazon.com/jp/elasticache/faqs/
- elasticacheでredisを作成
- ELBのセキュリティグループにredisポート(6379)を追加
- サーバー内部で
pecl install redisを実行 -
/etc/php/7.1/fpm/php.iniにextension=redis.soを追記 -
/etc/php/7.1/fpm/php.iniにsession.save_handler, session.save_pathを追記
session.save_handler = redis
session.save_path = ****.cache.amazonaws.com:6379
6 . phpinfoで確認
ちゃんとサーバーに反映されているか、phpinfoで確認
沈黙したアラート
先の懸念を潰しながらredisの完全移行を行い数日。
未だ、宿敵は現れず....
数時間に1回はひょっこりするやつが、数日も顔を出さないとは....
これにて、勝利宣言をさせていただく。
余談
アラート氏を監視している際にapach bench(以降ab でmemcachedとredisの負荷テストを行った。
負荷テストを行う環境で結果はかわるので、いくつか場所を変えて行う必要あり。
また、AWSはペネトレーションテストの事前申請がなくなったらしい。
Macはabが標準搭載されているが、サーバーで行う場合はインスコ要。
sudo apt install apache2-utils //abのパッケージのみを入れる
ab負荷テスト実行
redisの方が速い...!!
| 1秒間のリクエスト処理比較 | memcached | redis |
|---|---|---|
| ab -n 1000 -c 100 //10回×100人 | 41.93/sec | 41.53/sec |
| ab -n 10000 -c 100 //100回×100人 | 42.79/sec | 41.65/sec |
推測
memcached・redisにセルフDoSさながらの負荷をかけてもアラートが上がらなかった。
以上から、sessionが増えれば発生するアラートではないということがわかる。
総数の増大による発生ではなく、セッションの書き込みができないことによるものだからか？
サイトのPV数とセッションのアラート増加は時期的に関連しているように見えるが、根っこが未解明のまま。