13 パフォーマンスの監視およびプロファイリングの理解

EclipseLinkには、アプリケーションのパフォーマンスを測定し、最適化するための様々な機能が用意されています。ほとんどの機能はディスクリプタまたはセッションで有効/無効を切り替えることができるため、グローバルなパフォーマンスの向上が可能になります。

開発サイクルのどの段階でもパフォーマンスを考慮する必要があります。これは、設計および実装作業の中でパフォーマンスの問題を認識していることを意味しますが、最初の試みで最高のパフォーマンスを達成する必要があるわけではありません。

たとえば、最適化によって設計が複雑になる場合は、最適化作業を最終的な開発フェーズに回します。それでも、後の統合が簡単になるように、最初の段階から最適化の計画を立てることは必要です。

EclipseLinkには、パフォーマンスを監視してプロファイリングする次の方法が用意されています。

パフォーマンスのプロファイリング
フェッチ・グループの監視
パフォーマンスの監視
問合せの監視

13.1 パフォーマンスのプロファイリング

EclipseLinkパフォーマンス・プロファイラは、指定のセッション内で実行されたすべての問合せのパフォーマンス統計をロギングすることにより、パフォーマンスの問題を識別するために役立ちます。プロファイラの詳細は、『Oracle Fusion Middleware Oracle TopLinkソリューション・ガイド』のTopLink対応アプリケーションの監視および最適化に関する項を参照してください。

13.2 フェッチ・グループの監視

フェッチ・グループ・モニターを使用して、フェッチ・グループのフィールド使用状況を測定します。これは、複雑なシステムでパフォーマンス分析を行う場合に便利です。

システム・プロパティのorg.eclipse.persistence.fetchgroupmonitor=trueを使用してこのモニターを有効にします。

新しい属性がアクセスされるたびに、モニターによって、クラスで使用される属性がダンプされます。

フェッチ・グループの詳細は、6.2.1項「フェッチ・グループ」を参照してください。

13.3 パフォーマンスの監視

パフォーマンス・モニターを使用して、マルチスレッド・サーバー環境で詳細なプロファイリングおよび監視情報を提供します。

persistence.xmlで次のようにモニターを有効にします。

<property name="eclipselink.profiler" value="PerformanceMonitor"/>

パフォーマンス・モニターは、SessionCustomizerを使用するコードを通じて有効にすることもできます。

パフォーマンス・モニターによって、累積統計のダンプが1分ごとにEclipseLinkログに出力されます。

統計には、3つの情報セットが含まれます。

情報: セッション名やログイン時刻などの一定の情報データの統計です。
カウンタ: キャッシュ・ヒットや問合せ実行などの合計操作の累積カウンタの統計です。
タイマー: 特定のタイプの操作、読取り、書込み、データベース操作に対応する合計時間(ナノ秒)の累積測定の統計です。

統計は、通常、合計でグループ化されますが、問合せタイプ、問合せクラスおよび問合せ名によってもグループ化されます。カウンタとタイマーは、通常、同じ操作を対象に記録されるため、操作ごとの時間も計算可能です。

統計ダンプの間隔時間は、PerformanceMonitor APIのsetDumpTime(long) APIを使用して構成できます。結果のダンプを行わない場合、dumpTime属性をLong.MAX_VALUEなどの非常に大きな値に設定できます。統計には、getOperationTime(String) APIを使用してJavaプログラムでアクセスすることもできます。

パフォーマンス・モニターは、プロファイルの重みで構成することもできます。

プロファイルの重みは、次のようにSessionProfilerで定義します。

NONE: 統計は記録されません。
NORMAL: 情報統計が記録されます。
HEAVY: 情報、カウンタおよびタイマー統計が記録されます。
ALL: すべての統計が記録されます(これがデフォルトです)。

例13-1に、パフォーマンス・モニターによる出力例を示します。

例13-1 出力例

Performance Monitor:1279113281664
Operation     Value (ns)
Counter:CacheHits     1,375,664
Counter:CacheMisses     127
Counter:ClientSessionCreates     1,204,817
Counter:ConnectCalls     2
Counter:DataModifyQuery     48
Counter:DataModifyQuery:inventory     21
Counter:DataModifyQuery:order     27
Counter:DeleteObjectQuery     67,792
Counter:DeleteObjectQuery:Customer     1
...
Counter:ReadAllQuery     1,041,767.
Counter:ReadAllQuery:Item.findByCategory     733,827
Counter:ReadAllQuery:Item.findByCategory:CacheHits     733,779
Counter:ReadAllQuery:Item.findByCategory:CacheMisses     50
...
Counter:ReadObjectQuery     1,058,273
Counter:ReadObjectQuery:Item:item     130,063
Counter:ReadObjectQuery:Item:item:CacheHits     130,063
Counter:ReadObjectQuery:Item:item:CacheMisses     1
Counter:UnitOfWorkCommits     72,568
Counter:UnitOfWorkCreates     471,491
Counter:UnitOfWorkRollbacks     1
Counter:UpdateObjectQuery     71,498
Counter:UpdateObjectQuery:Customer     62,531
...
Info:LoginTime     Wed Jul 14 08:55:41 EDT 2010
Info:SessionName     file:/scratch/user_domains/servers/mt-1/app.jar
Timer:Caching     6,411,372,000
Timer:ConnectionManagement     17,225,641,000
Timer:DeleteObjectQuery     41,351,430,000
Timer:DeleteObjectQuery:Customer     4,441,000
Timer:DeleteObjectQuery:Customer:QueryPreparation     86,000
Timer:DeleteObjectQuery:Customer:SqlGeneration     28,000
Timer:DeleteObjectQuery:Customer:SqlPrepare     72,000
Timer:DeleteObjectQuery:Customer:StatementExecute     2,265,000
...
Timer:InsertObjectQuery     69,111,086,000
Timer:Logging     4,236,000
Timer:Merge     1,144,400,000
Timer:ObjectBuilding     31,914,397,000
Timer:QueryPreparation     984,396,000
Timer:ReadAllQuery     260,943,930,000
Timer:ReadAllQuery:Item:Item.findByCategory     14,790,333,000
Timer:ReadAllQuery:Item:Item.findByCategory:ObjectBuilding     250,959,000
Timer:ReadAllQuery:Item:Item.findByCategory:QueryPreparation     1,880,000
Timer:ReadAllQuery:Item:Item.findByCategory:RowFetch     113,552,000
Timer:ReadAllQuery:Item:Item.findByCategory:SqlGeneration     522,000
Timer:ReadAllQuery:Item:Item.findByCategory:SqlPrepare     2,055,000
Timer:ReadAllQuery:Item:Item.findByCategory:StatementExecute     107,382,000
...
Timer:Register     3,272,443,000
Timer:RowFetch     25,340,990,000
Timer:Sequencing     1,352,326,000
Timer:SqlGeneration     6,646,000
Timer:SqlPrepare     19,536,031,000
Timer:StatementExecute     508,589,220,000
Timer:TXAfterCompletion     1,854,152,000
Timer:TXBeforeCompletion     169,381,843,000
Timer:UnitOfWorkCommit     167,483,825,000
Timer:UpdateObjectQuery     46,440,589,000
Timer:UpdateObjectQuery:Customer     40,466,433,000
Timer:UpdateObjectQuery:Customer:QueryPreparation     867,496,000
Timer:UpdateObjectQuery:Customer:SqlGeneration     98,000
Timer:UpdateObjectQuery:Customer:SqlPrepare     1,319,333,000
Timer:UpdateObjectQuery:Customer:StatementExecute     32,901,366,000

13.4 問合せの監視

問合せモニターを使用して、問合せの実行およびキャッシュ・ヒットを測定します。これは、複雑なシステムでパフォーマンス分析を行う場合に便利です。

問合せモニターは次のいずれかの方法で有効にします。

システム・プロパティのorg.eclipse.persistence.querymonitor=trueを設定します。
persistence.xmlで、<property name="eclipselink.profiler" value="QueryMonitor"/>を設定します。

モニターによって、100秒に1回、問合せのキャッシュ・ヒットおよび実行(ミス)の数がダンプされます。

問合せの詳細は、第10章「問合せの理解」を参照してください。