test

Sun Java System Directory Server Enterprise Edition 6.3 トラブルシューティングガイド

応答しないプロセスのトラブルシューティング

次の表に示すように、発生するパフォーマンスの問題のタイプは使用可能な CPU のレベルにより異なります。稼働しているがクライアントアプリケーションの要求に応答しなくなった Directory Server のトラブルシューティングの第 1 段階は、パフォーマンスに関する 3 タイプの問題のどれに該当するかを特定することです。

表 5–1 CPU レベルおよび関係するパフォーマンスの問題

CPU レベル 

問題 

CPU = 0% 

パッシブハングアップ、サーバーはまったく応答しない 

CPU > 10% 

CPU < 90% 

パフォーマンスが低下、サーバーは動作するが期待する速度は得られない 

CPU = 100% 

アクティブハングアップ、サーバーはまったく応答しない 

この節のこのあとの部分では、次に示すトラブルシューティング手順について説明します。

応答しないプロセスの徴候

通常、エラーログにファイル記述子を開けないというエラーが含まれる場合、これは応答しないプロセスの徴候です。たとえば、次のようなメッセージがエラーログに含まれることがあります。


[17/Jan/2007:01:41:13 +0000] - ERROR<12293> - Connection  - conn=-1 
op=-1 msgId=-1 - fd limit exceeded Too many open file descriptors - not listening 
on new connection

その他の応答しないプロセスの徴候には、LDAP 接続が応答しないかハングアップする 、エラーログまたはアクセスログにメッセージが存在しない、アクセスログが更新されないなどがあります。

応答しないプロセスに関するデータの収集

prstat ツールは、CPU の使用量をスレッドごとに示します。prstat ツールの実行と同時に pstack ユーティリティーを使用してプロセススタックを収集する場合は、pstack の出力を使って問題発生時のスレッドの動作を確認できます。prstat および pstack を同時に何度も実行していくと、問題が同じスレッドで発生していたのか、また同じ関数呼び出しで発生していたのかを確認できます。パフォーマンスが低下している場合は、コマンドを 2 秒ごとに同時実行します。パッシブハングアップまたはアクティブハングアップが発生している場合は、コマンドを多少遅らせて (たとえば 10 秒ごとに) 実行します。

応答しないプロセスに関するデータの分析: 例

たとえば、次のように Directory Server 上で ldapsearch の実行を試みます。


# ldapsearch -p 5389 -D "cn=Directory Manager" -w secret 
-b"o=test" description=*

このコマンドにより 40 秒の検索が実行されますが、結果は得られません。プロセスが応答しない原因を分析するには、最初に次のコマンドを実行してプロセス ID を取得します。


# ps -aef | grep slapd | grep slapd-server1
   mares 15013 24159  0 13:06:20 pts/32   0:00 grep slapd-server1
   mares 14993     1  1 13:05:36 ?        0:04 ./ns-slapd -D
/u1/SUNWdsee/user1/52/slapd-server1 -i /u1/SUNWdsee/user1/52/slapd-s

次に、検索を再実行し、検索中に Directory Server プロセスに対して prstat および pstack コマンドを同時に実行します。上記の出力では、このプロセスのプロセス ID は 14993 です。


prstat -L -p 14993 0 1 > prstat.output ; pstack 14993 > pstack.output

2 秒の間隔をおいてコマンドを 3 回連続して実行します。

最初の prstat コマンドの出力は、次のようになります。


   PID USERNAME  SIZE   RSS STATE  PRI NICE      TIME  CPU PROCESS/LWPID      
 14993 mares     128M  110M cpu0    59    0   0:00.02 3.0% ns-slapd/51
 14993 mares     128M  110M sleep   59    0   0:00.49 1.3% ns-slapd/32
 14993 mares     128M  110M sleep   59    0   0:00.00 0.0% ns-slapd/16
 14993 mares     128M  110M sleep   59    0   0:00.00 0.0% ns-slapd/15
 14993 mares     128M  110M sleep   59    0   0:00.00 0.0% ns-slapd/14
 14993 mares     128M  110M sleep   59    0   0:00.00 0.0% ns-slapd/13
 14993 mares     128M  110M sleep   59    0   0:00.00 0.0% ns-slapd/12
 14993 mares     128M  110M sleep   59    0   0:00.00 0.0% ns-slapd/11
 14993 mares     128M  110M sleep   59    0   0:00.00 0.0% ns-slapd/10
 14993 mares     128M  110M sleep   59    0   0:00.00 0.0% ns-slapd/9
 14993 mares     128M  110M sleep   59    0   0:00.00 0.0% ns-slapd/8
 14993 mares     128M  110M sleep   59    0   0:00.00 0.0% ns-slapd/6
 14993 mares     128M  110M sleep   59    0   0:00.00 0.0% ns-slapd/5
 14993 mares     128M  110M sleep   59    0   0:00.00 0.0% ns-slapd/4
 14993 mares     128M  110M sleep   59    0   0:00.00 0.0% ns-slapd/3
Total: 1 processes, 51 lwps, load averages: 0.36, 0.29, 0.17

問題はスレッド 51 で発生しているようです。次に最初の pstack コマンドの出力内でスレッド 51 を検索すると、次のようになっています。


-----------------  lwp# 51 / thread# 51  --------------------
 ffffffff7eb55a78 ???????? (1, 102183a10, ffffffff70c1d340, 1001c5390, 0, 
ffffffff7ecea248)
 ffffffff77925fe0 id2entry (1002b7610, 1a09, 0, ffffffff70c1e7f4, 0, ffffffff77a6faa8) 
+ 3e8
 ffffffff7795ed20 ldbm_back_next_search_entry_ext (101cfcb90, 10190fd60, 0, 101b877b0, 
1a08, 45b4aa34) + 300
 ffffffff7ebaf6f8 ???????? (101cfcb90, 1002b7610, 1, ffffffff70c1eaf4, 0, 0)
 ffffffff7ebafbc4 ???????? (101cfcb90, 1, ffffffff70c1eaf4, 0, 10190fd60, 
ffffffff70c1e980)
 ffffffff7ebaf170 op_shared_search (101cfcb90, 0, 1015ad240, 0, ffffffffffffffff, 
ffffffff7ecea248) + 8c0
 ffffffff7e92efcc search_core_pb (101cfcb90, 2, 1000, 4000, ffffffff7ea4c810, 
ffffffff7ea56088) + 6c4
 ffffffff7e93a710 dispatch_operation_core_pb (101cfcb90, 101cfcb90, c00, 
ffffffff7ea4c810, 0, d10) + cc
 ffffffff7e926420 ???????? (101f3fe80, 102fd3250, 2, 63, 2, 200000)
 ffffffff7e92672c ldap_frontend_main_using_core_api (101f3fe80, 102fd3250, 2, 
101da1218, 10133db10, 0) + fc
 ffffffff7e927764 ???????? (220, 101c97310, ffffffffffffffff, 800, 958, 101f3fe80)
 ffffffff7d036a7c _pt_root (101c97310, ffffffff70b00000, 0, 0, 20000, ffffffff70c1ff48)
 + d4
 ffffffff7c1173bc _lwp_start (0, 0, 0, 0, 0, 0)
注 –

この例では、各行をページに納めるために行末を改行しています。

2 番目および 3 番目の pstack コマンドの出力では、スレッド 51 が同じタイプの操作を実行し、同じ結果が表示されます。

2 秒間隔で実行した 3 つの pstack の出力はすべて、スレッド 51 が同じ検索操作を実行していることを示しています。op_shared_search 関数の最初のパラメータには、実行される操作のアドレス (101cfcb90) が含まれます。3 つのスタックのそれぞれで同じ操作が実行されています。これは、最初と最後の pstack の実行間隔である 4 秒間に同じ検索が実行されていることを示します。さらに、prstat の出力は、スレッド 51 が CPU 使用量のもっとも高いスレッドであることを常に示しています。

アクセスログでハングアップ検出時の検索操作の結果を確認すると、これがインデックスを使用しない記述エントリ上での検索の結果であることがわかります。このハングアップは、記述インデックスを作成することで回避できます。

パフォーマンス低下のトラブルシューティング

この節では、パフォーマンス低下のトラブルシューティングを開始する方法について説明します。パフォーマンス低下の考えられる原因、およびパフォーマンスが低下したときに参照する必要のある情報、およびこの情報の分析方法について説明します。

パフォーマンス低下の考えられる原因

アクティブハングアップによるパフォーマンス低下と、パッシブハングアップによるパフォーマンス低下を混同しないようにしてください。パフォーマンスが低下している場合、次のいずれかの原因が考えられます。

パフォーマンス低下に関するデータの収集

パフォーマンス低下時のディスク、CPU、メモリー、およびプロセススタックの使用率に関する情報を収集します。

ディスク、CPU、およびメモリー統計の収集

CPU の使用率が非常に低い (10% 前後) 場合は、次のように netstat コマンドを使用して、ネットワーク関連の問題かどうかを確認します。


# netstat -an | grep port

アクセスログには結果がただちに送信されたことが示されているにもかかわらず、クライアントが情報を受信しない場合は、ネットワークにパフォーマンス低下の原因がある可能性があります。ping および traceroute コマンドを実行すると、ネットワークレイテンシが問題の原因であるかどうかを判別するのに役立ちます。

スワップ情報を収集して、メモリーが不足しているかどうかを確認します。swap コマンドの出力が小さい場合は、メモリーが問題の原因である可能性があります。

Solaris 

swap -l

HP-UX 

swapinfo

Linux 

free

Windows 

C:\report.txt に提供済み

Solaris では、prstat コマンドの出力を使用して、ほかのプロセスがシステムのパフォーマンスに影響を及ぼしているかどうかを確認します。Linux および HP-UX では、top コマンドを使用します。

Solaris での連続したプロセススタックの収集

「応答しないプロセスに関するデータの分析: 例」に記載の手順に従って、パフォーマンス低下時の Directory Server の連続した pstack および prstat 出力を収集します。たとえば、Solaris で次のスクリプトを使って pstack および prstat の情報を収集します。


#!/bin/sh

i=0
while [ "$i" -lt "10" ]
do
        echo "$i/n"
        date= `date"+%y%m%d:%H%M%S"
        prstate -L -p $1 0 1 > /tmp/prstate.$date
        pstack $1 > /tmp/pstack.$date
        i=`expr $i + 1`
        sleep 1
done

idsktune コマンドの使用

idsktune コマンドは、システムパラメータ、パッチレベル、チューニングの推奨事項に関する情報を提供します。このコマンドの出力を使用して、スレッドライブラリの問題や不足しているパッチを検出できます。idsktune コマンドの詳細については、idsktune(1M) のマニュアルページを参照してください。

パフォーマンスの問題に関する収集データの分析

一般に、データを通して発生したエラーのパターンや共通点を見つけます。たとえば、操作の問題がすべて静的グループの検索、静的グループの変更、およびロール上の検索に関連している場合、これら負荷の大きい操作を処理できるよう、Directory Server が適切に調整されていないことを意味します。たとえば、nsslapd-search-tune 属性が静的グループ関連の検索に合わせて正しく設定されていないか、グループ関連の更新が部分文字列内のインデックス生成属性 uniqueMember の影響を受けている可能性があります。問題と操作の間に関連性がないが、すべてが特定の時間に発生している場合は、メモリーアクセスまたはディスクアクセスの問題である可能性があります。

pstacks で集められた情報は、 SunSolve で unresponsive events という語句とともに検索すると、類似の問題が以前に発生して解決されていないかどうかを確認できます。SunSolve は http://sunsolve.sun.com/pub-cgi/show.pl?target=tous で参照できます。

この節の残りの部分では、前の手順で収集したデータを分析するのに役立つ補足的なヒントを提供します。

logconv コマンドを使用したアクセスログの分析

logconv コマンドを使用して、Directory Server アクセスログを分析できます。このコマンドは、使用状況に関する統計を抽出して、有意なイベントの数をカウントします。このツールの詳細については、logconv(1) のマニュアルページを参照してください。

たとえば、次のように logconv コマンドを実行します。


# logconv -s 50 -efcibaltnxgju access > analysis.access

出力されたファイルで、次の情報を確認します。

キャパシティーの限界の識別: 演習

キャパシティーの限界自体が、パフォーマンスの問題の原因になることがよくあります。パフォーマンスとキャパシティーを区別するため、パフォーマンスは「システムの処理速度」と定義し、キャパシティーは「システムまたは個別のコンポーネントの最大パフォーマンス」と定義します。

CPU の使用率が非常に低い (10% 前後) 場合は、ディスクコントローラが完全にロードされているかどうか、入出力が原因かどうかの判別を試みます。ディスクに問題があるかどうかを判別するには、次のように iostat ツールを使用します。


# iostat -xnMCz -T d 10

たとえば、インターネット上であるディレクトリが使用可能です。顧客は複数のサイトから検索を送信します。サービスレベル契約 (SLA) は、応答時間が 3 秒を超える要求の 5% に過ぎませんでした。現在、要求の 15% が 3 秒以上かかりますが、これはビジネスに不利益をもたらす状況です。システムは、900MHz の CPU を 12 基使用する 6800 です。

vmstat の出力は、次のようになります。


procs     memory            page            disk          faults      cpu
 r b w   swap  free  re  mf pi po fr de sr m0 m1 m1 m1   in   sy   cs us sy id
 0 2 0 8948920 5015176 374 642 10 12 13 0 2 1  2  1  2  132 2694 1315 14  3 83
 0 19 0 4089432 188224 466 474 50 276 278 0 55 5 5 4 3 7033 6191 2198 19  4 77
 0 19 0 4089232 188304 430 529 91 211 211 0 34 8 6 5 4 6956 9611 2377 16  5 79
 0 18 0 4085680 188168 556 758 96 218 217 0 40 12 4 6 4 6979 7659 2354 18 6 77
 0 18 0 4077656 188128 520 501 75 217 216 0 46 9 3 5 2 7044 8044 2188 17  5 78

右の 3 つの列 us=user、sy=system、および id=idle を参照すると、CPU の 50% 以上がアイドル状態にあり、パフォーマンスの問題に使用可能であることがわかります。メモリーの問題を検出する方法の 1 つは、vmstat の出力の sr (スキャンレート) 列を参照することです。ページスキャナが実行を開始しているか、スキャンレートが 0 より大きくなる場合、メモリーシステムをより詳細に確認する必要があります。この表示の奇妙な点は、左側に表示されるブロックされたキュー に 18 または 19 個のプロセスが含まれるのに、実行キューにはプロセスが存在していないことです。これは、Solaris 内のどこかで、プロセスが、使用可能な CPU をすべて使用せず、ブロックされていることを示しています。

次に入出力サブシステムを確認します。Solaris 8 では、iostat コマンドにスイッチ -C を指定するとコントローラレベルで入出力が集められます。次のように iostat コマンドを実行します。


#  iostat -xnMCz -T d
                    extended device statistics              
    r/s    w/s   Mr/s   Mw/s wait actv wsvc_t asvc_t  %w  %b device
  396.4   10.7    6.6    0.1  0.0 20.3    0.0   49.9   0 199 c1
  400.2    8.8    6.7    0.0  0.0 20.2    0.0   49.4   0 199 c3
  199.3    6.0    3.3    0.0  0.0 10.1    0.0   49.4   0  99 c1t0d0
  197.1    4.7    3.3    0.0  0.0 10.2    0.0   50.4   0 100 c1t1d0
  198.2    3.7    3.4    0.0  0.0  9.4    0.0   46.3   0  99 c3t0d0
  202.0    5.1    3.3    0.0  0.0 10.8    0.0   52.4   0 100 c3t1d0

コントローラ 1 では毎秒 396 回の読み取りを実行しており、コントローラ 3 では毎秒 400 回の読み取りを実行しています。データの右側を見ると、コントローラがほとんど 200% のビジー状態であることが出力からわかります。このため、個別のディスクが毎秒ほぼ 200 回の読み取りを実行しており、出力からディスクが 100% のビジー状態であることがわかります。このことから、大まかに言えば、個別のディスクが毎秒約 150 回の入出力を実行しています。これは、大規模なディスクアレイの LUN や LDEV には当てはまりません。これまでの数値の検証に基づき、各コントローラに 2 台のディスクを追加してデータを中継するという案が得られます。

この演習では、すべての数値に注意を向け、問題の特性を正確に把握することを試みました。CPU とメモリーを追加すればパフォーマンスの問題がすべて解決されると決め込まないようにしてください。この場合は、検索プログラムがディスクドライブのキャパシティーを超過しており、それがトランザクションで応答に極端に長い時間がかかるというパフォーマンスの問題を引き起こしていました。これらの CPU はすべて、ディスクドライブからの応答を待機していました。

プロセスのハングアップのトラブルシューティング

この節では、まったく応答しない Directory Server プロセスのトラブルシューティングについて説明します。まったく応答しないプロセスはハングアップと呼ばれます。発生する可能性のあるハングアップには、次の 2 種類があります。

この節の残りの部分では、各タイプのプロセスハングアップのトラブルシューティング方法について説明します。

アクティブハングアップのトラブルシューティング

top または vmstat 1 の出力に 95% を超える CPU レベルが表示される場合は、アクティブハングアップです。

この節では、アクティブハングアップの原因、アクティブハングアップの情報の収集方法、およびこのデータの分析方法について説明します。

アクティブハングアップの考えられる原因

アクティブハングアップの原因としては、次のことが考えられます。

アクティブハングアップのデータの収集と分析

Solaris システムでは、Solaris pstack ユーティリティーを使用して、ハングアップしている Directory Server プロセススタックの複数のトレースを収集します。このコマンドは、root-dir/bin/slapd/server ディレクトリから実行します。また、Solaris prstat ユーティリティーを使って、アクティブなプロセスに関する統計情報も収集してください。サーバーがハングアップしている間に、この情報を収集する必要があります。

連続している pstack および prstat データを毎秒収集してください。

パッシブハングアップのトラブルシューティング

top または vmstat 1 の出力に低い CPU レベルが表示される場合は、パッシブハングアップです。

パッシブハングアップの考えられる原因

パッシブハングアップの原因としては、次のことが考えられます。

パッシブハングアップのデータの収集と分析

Solaris システムでは、Solaris pstack ユーティリティーを使用して、ハングアップしている Directory Server プロセススタックの複数のトレースを収集します。このコマンドは、root-dir/bin/slapd/server ディレクトリから実行します。サーバーがハングアップしている間に、この情報を収集する必要があります。連続した pstack データを 3 秒ごとに収集してください。

サーバーがハングアップしている間に、サーバースレッドの状態が示された複数のコアファイルを収集します。これには、gcore コマンドを使用してコアファイルを生成し、コアファイルの名前を変更して、30 秒待ってから別のコアファイルを生成します。この手順をあと 1 回以上繰り返して、コアファイルと関連するデータのセットを 3 つ以上取得します。

コアファイルの生成の詳細については、「コアファイルの生成」を参照してください。