相関図おさらい
「心臓外科医の術式」、いろんなキャラクターが登場しますが、
今回もたろーちゃんの同期のAさんがまたまた登場します。
アプリケーション開発者からの相談
システムの「心臓」こと、Oracle Database に日々携わるたろーちゃん。
そんなたろーちゃんのところに、アプリケーション開発者のAさんが訪ねてきました。
今回は何があったのでしょうか？
Aさん「たろーちゃん、た、助けてくれ・・・。」
たろー「なんだ？いきなりどうした？」
Aさん「この前、log file sync 問題で助けてもらったけど、今度は別なシステムで log file sync で遅延が発生して困ってるんだ。」
※その時のシステムについては、以前の記事『強敵！log file sync』の回を参照して下さい。
たろー「また log file sync？」
Aさん「うん。悪いけど、またちょっと見てくれないか？」
たろーちゃんは、データベースサーバの構成を詳しく聞くことにしました。
● Real Application Clusters 構成（19c Enterprise Edition ２ノード RAC ）
● Oracle Diagnostics Pack オプションあり。
たろー「ほう、今度は２ノードの RAC 構成か。」
Aさん「そうなんだ。このシステムでは キャッシュフュージョン を避けるために、片系のインスタンスに処理を寄せて動作させているんだよ。」
たろー「なるほど。HA 構成のような使い方をしているんだな。」
Aさん「うん。アプリケーションの特性上、 キャッシュフュージョン が発生し易いため、敢えてそうしてるんだよ。」
たろー「ふむ。まずは AWR レポートを見てみよう。」
たろーちゃんは、事象発生時の AWR レポートを見ることにしました。
■インスタンス１側の AWR レポート
■インスタンス２側の AWR レポート
たろー「インスタンス１側の log file sync が突出して多いな。一方、インスタンス２側は殆ど負荷がかかってなさそうだ。」
Aさん「うん。インスタンス１側にアクセスを寄せているからな。」
たろーちゃんは、更に AWR レポートを読み進めていきました。
たろー「log file sync での待機時間は 3,466 秒か。」
Aさん「メチャクチャ待機してるな。」
たろー「それに対して log file parallel write の待機時間は 18 秒か。」
Aさん「それは確か、バックグラウンドプロセス（LGWR）が待たされた時間だったよな？」
たろー「そうだ。よく覚えているな。」
Aさん「まぁ前回、あれだけ勉強したからな（ドヤッ）。」
たろー「log file parallel write の待機時間が 18 秒ということは、I/O には問題なさそうだな。」
Aさん「ふむ。」
たろー「log file sync の内訳を見てみるか。」
たろー「すごいな、こりゃ。
ヒストグラムを見ると log file sync に数秒かかっているのがチラホラあるな。」
Aさん「普通はどれくらいなんだ？」
たろー「環境やワークロードにもよるけど、大体マイクロ秒のオーダーだよ。」
Aさん「ふーむ・・・。」
たろー「診るまでもないと思うが、『血液検査』をしておくか。」
たろーちゃんは該当時間帯の V$ACTIVE_SESSION_HISTORY の情報を調べることにしました。
※ V$ACTIVE_SESSION_HISTORY に関しては以前の記事『正体不明のパフォーマンス悪化の謎を解き明かせ！』の回をご参照下さい。
血液検査の結果は？
たろー「やはり log file sync が多発しているな。」
Aさん「どういうことだ？前回のこともあり、試しに Scalable Log Writer 機能を無効にしてみたんだが、状況は変わらなかったんだ。」
たろー「・・・それ以外の何か別な問題があるってことさ。」
さて、こうなると厄介だぞ。
log file sync には前回、散々苦しめられたからな（汗）
調査続行
Aさん「どうしたらいいかな、たろーちゃん？」
たろー「・・・とりあえず、基本に戻るか。
該当時間帯のアラートログやトレースファイルを見てみよう。」
たろーちゃんはサーバにログインし、該当時間帯のアラートログやトレースファイルを調査し始めました。
すると・・・。
たろー「おや？これは・・・」
＜/u01/app/oracle/diag/rdbms/orcl/orcl1/trace/orcl1_lms0_8860_8865.trc＞
Trace file /u01/app/oracle/diag/rdbms/orcl/orcl1/trace/orcl1_lms0_8860_8865.trc Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production Version 19.2.0.0.0 Build label: RDBMS_19.2.0.0.0_LINUX.X64_190204 ORACLE_HOME: /u01/app/oracle/product/19.0.0/dbhome_1 System name: Linux Node name: node1 Release: 4.1.12-124.24.3.el7uek.x86_64 Version: #2 SMP Mon Jan 14 15:04:40 PST 2019 Machine: x86_64 Storage: Exadata Instance name: orcl1 Redo thread mounted by this instance: 0 Oracle process number: 26 Unix process pid: 8860, thread id: 8865, image: node1 (LMS0) *** 2019-11-01 10:33:36.241 (CDB$ROOT(1)) *** SESSION ID:(332.19470) 2019-11-01 10:33:36.241 *** CLIENT ID:() 2019-11-01 10:33:36.241 *** SERVICE NAME:() 2019-11-01 10:33:36.241 *** MODULE NAME:() 2019-11-01 10:33:36.241 *** ACTION NAME:() 2019-11-01 10:33:36.241 *** CLIENT DRIVER:() 2019-11-01 10:33:36.241 *** CONTAINER ID:(1) 2019-11-01 10:33:36.241 * KJM HIST - Cheap us TRUE Cheap sec TRUE *** 2019-11-01 14:41:54.158 (CDB$ROOT(1)) Warning: log write broadcast wait time 511ms (SCN 0x2cfea0f0) *** 2019-11-01 14:41:48.261 (CDB$ROOT(1)) Warning: log write broadcast wait time 2427ms (SCN 0x2cfeeecc) *** 2019-11-01 14:42:39.574 (CDB$ROOT(1)) Warning: log write broadcast wait time 2178ms (SCN 0x2cffeda4) *** 2019-11-01 14:43:36.961 (CDB$ROOT(1)) Warning: log write broadcast wait time 2046ms (SCN 0x2d00e74c) *** 2019-11-01 14:44:07.240 (CDB$ROOT(1)) Warning: log write broadcast wait time 2611ms (SCN 0x2d01b144) *** 2019-11-01 14:44:07.247 (CDB$ROOT(1)) Warning: log write broadcast wait time 2596ms (SCN 0x2d01b1a2) *** 2019-11-01 14:44:25.357 (CDB$ROOT(1)) Warning: log write broadcast wait time 1125ms (SCN 0x2d021b10) *** 2019-11-01 14:45:07.484 (CDB$ROOT(1)) Warning: log write broadcast wait time 674ms (SCN 0x2d033304) *** 2019-11-01 14:45:08.142 (CDB$ROOT(1)) Warning: log write broadcast wait time 826ms (SCN 0x2d0544c2) *** 2019-11-01 14:45:32.300 (CDB$ROOT(1)) Warning: log write broadcast wait time 2371ms (SCN 0x2d05b002) *** 2019-11-01 14:46:05.400 (CDB$ROOT(1)) Warning: log write broadcast wait time 1317ms (SCN 0x2d05ff64) *** 2019-11-01 14:46:32.709 (CDB$ROOT(1)) Warning: log write broadcast wait time 759ms (SCN 0x2d070890) ：：： ：：： ：：： （略）
Aさん「なんか Warninng が出てるな？」
たろー「・・・・・。」
Aさん「『log write broadcast wait time』？ なんだそれは？」
こ、この現象は・・・。
次回、たろーちゃんが謎のメッセージに挑みます！
乞うご期待！！
クックックッ、前にも言っただろう？
君には、私（log file sync）のトリックは決して見破れないよ？
投稿者プロフィール
