|
本ブログでは、MarkLogicのコンサルティングを行う中でもよく聞かれる、クエリ問題が発生した際の切り分け手法について紹介します。
現在起きている問題の切り分け手法
MarkLogic内で何かしらの処理に問題がありそうだと思っても、具体的にどの処理に問題があるのかわからないといった経験はないでしょうか。
そういった場合、大きく2つの手法(現在と過去分析)が考えられます。
まず最初にすべきことは、現在何が起きているかを知ることです。
MarkLogicクラスタは複数のアプリケーションサーバを構成することができますが、この段階ではどのアプリケーションに問題があるのかわからない事があります。
その際は、まず下記Admin UI(ポート8001)のクラスタステータスページにアクセスしてみましょう。
http://<your-server>:8001/cluster-status.xqy
このページでは各サーバごとに長時間リクエスト(Oldest Request)を確認することができます。
最初の切り分けとしては、長時間リクエスト(Oldest Request)、または平均処理時間(Average Time)が最も長いサーバを特定します。
図1: Admin UI クラスタステータスページ
問題のサーバを特定したら画面上のアプリケーションサーバ名をクリックします。
クリックすると対象サーバの詳細画面に遷移し、サーバ上で実行されているクエリの一覧が表示されます。
次に“show more”ボタンをクリックし、クエリのフルパスを表示します。(“…”となる場合はマウスオーバーするとフルパスを取得できます)
続けて問題処理の再現テストを行う場合、QueryConsole (MarkLogicのクエリ実行インターフェース)を使う事ができますが、その際に必要となるinput情報を考えます。
大抵の場合はクエリ自体から情報が揃いますが、POST/PUTリクエストなどリクエストボディが必要な場合は[stack]リンクを選択します。
この[stack]リンクは問題処理が実行されているサーバ上のAdmin UIにのみ表示されます。
図2: App Serverステータスページで現在実行されているクエリの情報を確認
過去に起きた問題の切り分け手法
2つめの手法として、問題が過去に起きていた場合に実施する切り分けです。
Admin UIは現在の情報しか確認できないため、ここでは別のツールを利用します。
目的は先程と変わらず、問題の処理を特定し再現ケースを作ることです。
まずはMonitoring Historyツールから始めてみましょう。
Monitoring Historyには下記ポート8002からアクセスできます。
http://<your-server>:8002/history/
このツールを使うことで、問題を時間軸で深堀りすることができます。
リソースごとにセクションが分割されているので、グラフのスパイクポイント(跳ね上がっている部分)に着眼し問題を切り分けることができます。
画面左上にあるTIME SPANで対象の時間帯を設定できますが、まずはStart/Endを直近の24時間にし、Periodを”raw”にしてみましょう。
時間間隔はShortcutから”1d”を選択すると直近24時間となります。
また、Periodをrawにすることでより細かい粒度で分析することが可能です。
次にグラフをみていきますが、はじめに見るポイントとしてはサーバセクションです。グラフは複数のラインで構成されていますが、各々がアプリケーションサーバを示しています。
グラフから問題の時間帯とアプリケーションサーバを特定したら、MarkLogicのアクセスログを確認してみましょう。
デフォルトではログは7日間分保存されています。
ログはサーバ上、あるいはAdmin UIから下記のようにアクセスして確認することができます。
http://<your-server>:8001/error-logs.xqy
ログサイズは非常に大きいことがあるため、ダウンロードしてローカル端末のテキストエディタ等を使用して確認します。
図3: Admin UI上から確認できるログ一覧画面
対象のアクセスログをエディタで開いたら、問題の時間帯についてログを確認します。アクセスログは追記型ですので、上の行に行くほど古く、一番下が最新の内容となります。
また、各行にはタイムスタンプが付いているため、これをもとに対象の時間帯を確認します。対象のクエリを特定したら、クエリ文字列からいくつかのinput情報を取得できます。
ただし、POST/PUTのペイロードは見れないため、これらは同時刻のエラーログから確認します。
::1 - - [29/Aug/2017:16:49:53 -0400] "GET /v1/resources/search?rs:excludeOverrides=1&rs:format=json&rs:howtoTab=false&rs:pageLength=10&rs:q=water&rs:returnAnswers=true&rs:sort=relevancy&rs:spell-correct=true&rs:start=1&rs:structuredQuery=%7B%22query%22:%7B%22queries%22:%5B%7B%22and-query%22:%7B%22queries%22:%5B%5D%7D%7D%5D%7D%7D&rs:tabName=All&rs:weightFile=weights HTTP/1.1" 500 1830 - "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/60.0.3112.113 Safari/537.36"
図4: アクセスログの例
クエリの再現
クエリの再現に最も簡単な方法は、ポート8000のQuery Console を使用することです。
http://<your-server>:8000/qconsole
前項で取得したinput情報に加え、必要に応じてコードを編集します。(inputにハードコードされたhttpまたは静的変数の除去など)
Query Console 上でコードが動くようになったら、プロファイル機能を使って分析します。
仮に問題が特定のクエリであった場合、xdmp:plan() や xdmp:query-trace(fn:true()) を利用して問題を深堀りします。
または、遅い部分のみを別のQuery Consoleタブにコピーしプロファイル機能を使うことも良いでしょう。
もし、cts:search() に問題があった場合は、クエリオプションを確認し、”filtered”または “unfiltered”が明示的に指定されていないかを見ます。
”filtered”が指定されていた場合は、クエリがインデックスで解決できないかを確認し、可能な場合はより効率的な“unfiltered”を使用するようにします。
あるいはクエリボリュームを [1 to 100]のように制限して、クエリのどの部分に問題がありそうかを切り分けることも有効です。
図5: Query Consoleのプロファイル機能
Query Consoleで実行した際に処理が速かった場合は、サーバ高負荷や他のクエリによる問題である可能性があります。
その場合、例えば問題の時間帯に流れていたクエリの一部を同時実行し、処理遅延が発生するかを見ることも有効です。
もし処理の遅延が発生した場合は、クエリの競合を疑います。
また、パフォーマンス問題の再現テストの場合には、キャッシュについても考慮することが重要です。LIST CACHEあるいはEXPANDED TREE CACHEといったキャッシュに より2回目のリクエストが速くなる可能性があるためです。一番簡単な方法としては本番同等環境の検証環境等でMarkLogicを再起動しキャッシュクリアしてからテストします。
また、キャッシュを明示的にクリアする関数も用意されています。各関数は実行したホスト上のキャッシュをクリアします。そのため関数を利用する場合は、全てのホストで実行する必要があります。
これらの関数は空のシーケンスを返します。そのため、うまくいったかどうかは xdmp:cache-status()を前後で実行しキャッシュの状態から確認します。
キャッシュクリア関数:
xdmp:list-cache-clear()xdmp:expanded-tree-cache-clear()xdmp:compressed-tree-cache-clear()xdmp:triple-cache-clear()xdmp:triple-value-cache-clear()
次のステップ
今回は問題のクエリの特定、及び再現実行のためのinput情報の取得、Query Consoleでの再現テストの手法について紹介しました。
ただし、これらはパフォーマンストラブルシューティングの第一歩となる切り分け手法ですので、実際にはコードの書き換えやデータベース設定が必要になることがあります。
更に詳しく知りたい方は下記情報を確認してみてください。
The post MarkLogicにおけるクエリ問題切り分け手法 appeared first on MarkLogic.
| 