メールディーラー、長い長い戦いの歴史

クラウドやSaaSという言葉が認知度を高めるもっと以前から提供されていたメールディーラー。
クラウド時代の荒波とともに幾多のトラブルも乗り越えてきました。
メールディーラーの開発に関わった歴戦の勇士たちから聞き集めた数々のトラブルと、それらをどうやって解決していったのかをご紹介します。

・PHPのPostgreSQL関数起因によるメモリ枯渇と対応の軌跡
・リリース時に発生したファイル参照エラーに対してファイルシステムの挙動と格闘した話

Transcript

1. #RAKUSMeetup ©2019 RAKUS Co., Ltd. ©2019 RAKUS Co., Ltd. メールディーラー、 長い長い戦いの歴史 開発統括部 第二開発部 カスタマーサービス・クラウド開発課 中尾 圭 1
2. #RAKUSMeetup ©2019 RAKUS Co., Ltd. 自己紹介 • 中尾 圭（ナカオ ケイ）40才 • 入社11年目 • Mail Dealer の機能開発を担当（過去には配配メールも） • 中３♂、小６♀の父 • 好きな音楽：ジャズ／フュージョン • 好きなクラブ：ガンバ大阪 • 好きなプロテイン：ビーレジェンド ミルキー味 2
3. #RAKUSMeetup ©2019 RAKUS Co., Ltd. Mail Dealer(MD) とは クラウド型のメール共有・管理システム 3
4. #RAKUSMeetup ©2019 RAKUS Co., Ltd. Mail Dealer(MD) とは 2002年頃にはクラウドサービスとして提供されていた。 • 2006年にはクラウドコンピューティングという言葉が普及し、クラウドコンピューティング上 で提供されるソフトウェアがSaaSと呼ばれるようになった。 ウィキペディア：SaaS(https://ja.wikipedia.org/wiki/SaaS) • 「クラウドコンピューティング」の用語を最初に使用したのは、2006年 Google CEOのエリッ ク・シュミットによる発言だとされ、 ウィキペディア：クラウドコンピューティング (https://ja.wikipedia.org/wiki/%E3%82%AF%E3%83%A9%E3%82%A6%E3%83%89%E3%82%B3%E3%83%B3%E3%83%94%E3%83%A5%E3%83%BC%E3%83%86%E3%82%A3%E3%83%B3%E3%82%B0) • この「ASP」という用語自体は1998年ころから用いられるようになった比較的新しい用語ではあ るが、 ウィキペディア：アプリケーションサービスプロバイダ (https://ja.wikipedia.org/wiki/%E3%82%A2%E3%83%97%E3%83%AA%E3%82%B1%E3%83%BC%E3%82%B7%E3%83%A7%E3%83%B3%E3%82%B5%E3%83%BC%E3%83%93%E3%82%B9%E3%83%97%E3%83%AD%E3%83%90%E3%82%A4 %E3%83%80) 4
5. #RAKUSMeetup ©2019 RAKUS Co., Ltd. 本日の内容 •バージョンアップしたら画面が真っ白に。 •PHPの実行ファイルがnot found。 5
6. #RAKUSMeetup ©2019 RAKUS Co., Ltd. ©2019 RAKUS Co., Ltd. バージョンアップしたら画面が真っ白に
7. #RAKUSMeetup ©2019 RAKUS Co., Ltd. バージョンアップしたら画面が真っ白に。 • メジャーバージョンアップ後、特定の環境、特定の画面で 真っ白になってしまうとカスタマーサポートチームから報 告。 • さらに、別の環境（サーバ）では、ログインしようとした ら画面が真っ白になってしまうという報告も。
8. #RAKUSMeetup ©2019 RAKUS Co., Ltd. ログイン後に画面が真っ白 ログイン！
9. #RAKUSMeetup ©2019 RAKUS Co., Ltd. サーバのログを調査 •PHPのログに不穏な文字列発見 [16-Apr-2019 11:40:59 Asia/Tokyo] PHP Fatal error: Allowed memory size of *** bytes exhausted (tried to allocate *** bytes) in /usr/local/programA.php on line 1879 [16-Apr-2019 15:45:10 Asia/Tokyo] PHP Fatal error: Allowed memory size of *** bytes exhausted (tried to allocate *** bytes) in /usr/local/programB.php on line 1245
10. #RAKUSMeetup ©2019 RAKUS Co., Ltd. メモリ不足の原因の予測 •ループ処理でとても長い配列や文字列を作って しまっている。
11. #RAKUSMeetup ©2019 RAKUS Co., Ltd. 調査の結果 • ログに直接的に表示されている行の場所でメモリ肥大化 につながる処理は見当たらなかった。 しかしメモリオーバーが発生していることは間違いない。 • でもどの処理によってメモリオーバーが発生しているの かがよくわからない。
12. #RAKUSMeetup ©2019 RAKUS Co., Ltd. そのあとやったこと •プログラムの通り道にメモリの利用状況をログ に吐き出すよう、ひたすらに埋め込む。 some process; err(“memory_get_usage : ” . memory_get_usage()); some process; err(“memory_get_usage : ” . memory_get_usage()); some process; err(“memory_get_usage : ” . memory_get_usage());
13. #RAKUSMeetup ©2019 RAKUS Co., Ltd. メモリが激増している場所を発見 04/16 18:48[error] [programZ:14 > db.php:1257] memory_get_usage : 7891176 04/16 18:48[error] [programZ:14 > db.php:1259] memory_get_usage : 7891176 04/16 18:48[error] [programZ:14 > db.php:1261] memory_get_usage : 7891208 04/16 18:48[error] [programZ:14 > db.php:1263] memory_get_usage : 58113328 04/16 18:48[error] [programZ:14 > db.php:1259] memory_get_usage : 58113704 04/16 18:48[error] [programZ:14 > db.php:1261] memory_get_usage : 58113736
14. #RAKUSMeetup ©2019 RAKUS Co., Ltd. 原因の行を特定 function getMetaInfoHash($aTable) { # 対象テーブルのメタ情報を取得 $metaHash = Array(); $sql = "select * from $aTable where false"; $result = @pg_query($this->mCon, $sql); for ($i = 0; pg_num_fields($result) > $i; $i++) { $lName = pg_field_name($result, $i); err("memory_get_usage : " . memory_get_usage()); $lNum = pg_field_type($result, $i); err("memory_get_usage : " . memory_get_usage()); $metaHash[$lName] = $lNum; } return $metaHash; } ここでメモリ使用量が激増
15. #RAKUSMeetup ©2019 RAKUS Co., Ltd. pg_field_type()
16. #RAKUSMeetup ©2019 RAKUS Co., Ltd. pg_field_type() •pg_field_type()に問題があると当たりをつけて調査 を開始。 •関数名で調べるといくつかのブログやツイートが見 つかり、pg_field_type()には、パフォーマンス的に 問題があるっぽいことがわかった。
17. #RAKUSMeetup ©2019 RAKUS Co., Ltd. pg_field_type()のソースを確認
18. #RAKUSMeetup ©2019 RAKUS Co., Ltd. pg_field_type()部分のソース •１つのテーブルのカラムの情報を得たいだけなのに、 DB内のすべてのカラムを取得していた。 if ((result = PQexec(pgsql, "select oid,typname from pg_type")) == NULL || PQresultStatus(result) != PGRES_TUPLES_OK) { if (result) { PQclear(result); } smart_str_free(&str); return estrndup("", sizeof("") - 1); }
19. #RAKUSMeetup ©2019 RAKUS Co., Ltd. 解決に向けて •テーブルのデータ型を取得するのを pg_field_type()に頼るのをやめ、自作する。 •自作関数では対象のテーブルからのみ情報を selectするようにした。
20. #RAKUSMeetup ©2019 RAKUS Co., Ltd. function original_get_field_types($aTable) { $hash = []; $sql = "select"; $sql .= " at.attname,"; $sql .= " format_type(at.atttypid, at.atttypmod)"; $sql .= " from"; $sql .= " pg_attribute as at"; $sql .= " left join pg_type as tp on (at.atttypid = tp.oid)"; $sql .= " where"; $sql .= " at.attnum > 0 and"; $sql .= " at.attrelid = (select oid from pg_class where relname = '{$aTable}')"; $sql .= " order by"; $sql .= " at.attnum"; $result = @pg_query($this->mCon, $sql); for ($i = 0; $i < @pg_num_rows($result); $i++) { $row = @pg_fetch_object($result, $i); $hash[$row->attname] = $row->format_type; } return $hash; } pg_field_type()を自作で置き換え
21. #RAKUSMeetup ©2019 RAKUS Co., Ltd. 解決 該当のサーバ、画面が真っ白になる事象は解決。 バージョンアップを続けることにより、テーブル／カラムが増えて pg_field_type()で利用するメモリが限界を超えてしまった。 この関数はあちこちから呼ばれていたので全体的に速度が向上した。 ※個人の感想であり、効果・効能を示すものではありません。
22. #RAKUSMeetup ©2019 RAKUS Co., Ltd. ©2019 RAKUS Co., Ltd. PHPの実行ファイルがnot found
23. #RAKUSMeetup ©2019 RAKUS Co., Ltd. PHPの実行ファイルがnot found •ある日検出したPHPのエラー ファイルが見つからない…（#^ω^） [03-Jul-2018 12:24:01 Asia/Tokyo] PHP Fatal error: Class ‘Parser’ not found in /usr/local/**/maildealer.php on line 1067
24. #RAKUSMeetup ©2019 RAKUS Co., Ltd. やったこと •本当にそのファイルが存在していないのかを調べる。 →ファイルは存在していた。 •開発メンバそれぞれ、胸に手を当ててその時間に何 をしていたのかを考える。
25. #RAKUSMeetup ©2019 RAKUS Co., Ltd. わかったこと •その時間にメールディーラーのバージョンアップが 行われていた。…これが原因かな…ざわざわ… •バージョンアップ時のプログラムのデプロイは、古 来より使われているメールディーラーバージョン アップスクリプトが使われていた。
26. #RAKUSMeetup ©2019 RAKUS Co., Ltd. バージョンアップスクリプトを調査 • 緑の字は実際に動いているプログラム。 旧プログラムをmvでいったん退避させてから新プログラ ムをcpで配置している。 /bin/mv -f {$_INSTALL_PATH}/phpDir {$_INSTALL_PATH}/phpDir_{$date} /bin/mv -f {$_INSTALL_PATH}/rakusLibDir {$_INSTALL_PATH}/rakusLibDir_{$date} /bin/mv -f {$_INSTALL_PATH}/bin {$_INSTALL_PATH}/bin_{$date} /bin/cp -ar ./phpDir {$_INSTALL_PATH}/phpDir /bin/cp -ar ./rakusLibDir {$_INSTALL_PATH}/rakusLibDir /bin/cp -ar ./bin {$_INSTALL_PATH}/bin
27. #RAKUSMeetup ©2019 RAKUS Co., Ltd. 原因 •そらそうだ。 •この仕組みを変更することにした。 /bin/mv -f {$_INSTALL_PATH}/phpDir {$_INSTALL_PATH}/phpDir_{$date} /bin/mv -f {$_INSTALL_PATH}/rakusLibDir {$_INSTALL_PATH}/rakusLibDir_{$date} /bin/mv -f {$_INSTALL_PATH}/bin {$_INSTALL_PATH}/bin_{$date} ※ここのタイミングでアクセスがあるとnot foundが発生する☆彡 /bin/cp -ar ./phpDir {$_INSTALL_PATH}/phpDir /bin/cp -ar ./rakusLibDir {$_INSTALL_PATH}/rakusLibDir /bin/cp -ar ./bin {$_INSTALL_PATH}/bin
28. #RAKUSMeetup ©2019 RAKUS Co., Ltd. シンボリックリンクへ変更する作戦 •mvしてからcpするのをやめる。 •プログラムへの経路はシンボリックリンクにし、旧 プログラムから新プログラムへのシンボリックリン クのリンク先変更により一瞬でもプログラムが存在 しないことは防げる。
29. #RAKUSMeetup ©2019 RAKUS Co., Ltd. 図解 1. 新しいプログラム「phpDir_new」を配置する。 2. デプロイのときには、旧プログラム(phpDir_old)に向いていたシンボリックリンクを新 プログラム(phpDir_new)に向くよう変更する。 3. これにより、プログラムが存在しない瞬間がなくなる。 /usr/local/phpDir phpDir_old phpDir_new シンボリックリンク
30. #RAKUSMeetup ©2019 RAKUS Co., Ltd. しかし… •またもや発生。シンボリックリンクのリンク先 を変更するように修正したのに… •再度原因の調査を開始。 [01-Aug-2018 15:00:01 Asia/Tokyo] PHP Fatal error: Class ‘Parser’ not found in /usr/local/**/maildealer.php on line 1067
31. #RAKUSMeetup ©2019 RAKUS Co., Ltd. 仮説 •lnコマンドでのリンク先変更であっても、処理 中に割り込まれるとnot foundが発生する？ lnコマンドでのリンク先変更の処理をstraceを 使って詳細に見てみよう。
32. #RAKUSMeetup ©2019 RAKUS Co., Ltd. straceとは •straceの後ろに書いたコマンドが実行され、そ のときのシステムコール一覧が表示される。 •これによりプロセスの挙動を追いかけることが できる。
33. #RAKUSMeetup ©2019 RAKUS Co., Ltd. 動作確認 •リンク先の変更時の挙動をstraceで確認する。 > ln -s ./dir1 slDir > strace ln -nfs ./dir2 slDir symlink("./dir2", "slDir") = -1 EEXIST (File exists) unlink("slDir") = 0 symlink("./dir2", "slDir") = 0 •straceの実行結果（抜粋）
34. #RAKUSMeetup ©2019 RAKUS Co., Ltd. わかったこと •lnコマンドでのリンク先変更では、以下の挙動 になっていた。 1. unlinkでリンクを削除 2. symlinkでシンボリックリンクを作成 ※ここのタイミングでアクセスがあるとnot foundが発生する☆彡
35. #RAKUSMeetup ©2019 RAKUS Co., Ltd. 対策を検討 • リンク先を変更する方法では、同様の事象が起きることは確 認できた。次に以下の方法を検討。 1. 新しいプログラムにリンクするシンボリックリンクを作成 する。 2. 旧プログラムにリンクするシンボリックリンクを新シンボ リックリンクでmvにより上書きする。
36. #RAKUSMeetup ©2019 RAKUS Co., Ltd. 図解 1.新しいプログラムにリンクしたphpDir_releaseを作成する。 2.旧プログラムにリンクしているphpDirをphpDir_releaseで上書 き(mv)する。 /usr/local/phpDir phpDir_old phpDir_new /usr/local/phpDir_release mv
37. #RAKUSMeetup ©2019 RAKUS Co., Ltd. 動作確認 > ln -s ./dir1 slDir > ln -s ./dir2 slDir_new > strace mv -f slDir_new slDir rename("slDir_new", "slDir/slDir_new") = 0 •straceの実行結果（抜粋）
38. #RAKUSMeetup ©2019 RAKUS Co., Ltd. それ以降 •同様のnot foundエラー通知を受け取ることはな くなった。
39. #RAKUSMeetup ©2019 RAKUS Co., Ltd. ©2019 RAKUS Co., Ltd. まとめ
40. #RAKUSMeetup ©2019 RAKUS Co., Ltd. まとめ 古くから稼働しているサービス内で今まで問題のない部分であっても 急に問題が表面化することがある。 「今までずっと大丈夫だったから」という固定観念にとらわれず調査 することが大事。 今、新たに実装するものも「長い年月が経ったときにも問題ないか」 という視点が大事。 とはいえ、先を見据えすぎてこってりしすぎたり複雑になるのは避け たい。バランス大事。 40
41. #RAKUSMeetup ©2019 RAKUS Co., Ltd. 出典 •PHP5からPHP7にしたらいろいろ変わってた https://qiita.com/hirohiro77/items/8dc2adcdfac6425c9d1e •@DQNEO https://twitter.com/dqneo/status/619800551782379520 •アトミックなシンボリックリンク更新 https://qiita.com/dalance/items/d2d2feb720172036fd22
42. #RAKUSMeetup ©2019 RAKUS Co., Ltd. ©2019 RAKUS Co., Ltd. ご清聴ありがとうございました。