イベントハンドラーの問題の分析

検索

最終更新日 : Apr 27, 2021 11:59:42 PM GMT | 次にも適用 : CQ

問題点

logs/crx/error.log file に次のエラー場表示されます：

* WARN* ObservationDispatcher: キューの 200000 以上のイベント

または、データのインポート中にシステムが低速になります。

解決策

問題を分析するには、次の手順を実行します。

各 JCR イベントリスナーの実行のタイミングを提供する EventConsumer デバッグを作成します。
問題再現し、スレッドダンプをし、プロファイラーを実行して、問題の原因になっているコードまたはコンテンツの詳細を収集します。
問題を修正するコードを修正し、問題の原因となっているコンテンツをクリーンアップするか、問題が製品コードに関連する場合は AEM（CQ）サポートにお問い合わせください。

1. EventConsumer デバッグログを作成します

CQ5.4/CRX2.2 またはそれ以前のバージョン

CQ を停止します。
crx-quickstart/server/runtime/0/_crx/WEB-INF/log4j.xml におけるログレベルを次のように設定します。<logger name="org.apache.jackrabbit.core.observation.EventConsumer">
<level value="debug" />
</logger>
CQ を開始します。
ここで、logs/crx/error.log で、org.apache.jackrabbit.core.observation.EventConsumer からのデバッグログが表示され、各イベントハンドラーの実行時間が示されます。

CQ5.5/CRX2.3 またはそれ以降のバージョン（AEM バージョンを含む）：

http://host:port/system/console/configMgr に移動し、管理者権限でログインしてください。
Apache Sling Logging Logger ファクトリを探し、ファクトリ設定の右側にある + ボタンをクリックしてインスタンスを作成します。この手順では、新しいログロガーを作成します。
次の設定を使用して、設定します。
ログレベル：DEBUG
　ログファイルパス：logs/eventconsumer.log
　カテゴリ：org.apache.jackrabbit.core.observation.EventConsumer
これで、logs/eventconsumer.log に org.apache.jackrabbit.core.observation.EventConsumer から、各イベントハンドラーの実行時間を表示したデバッグログメッセージが表示されます。

2. 問題を再現します

デバッグログファイルがあるので、イベントがパイルアップする原因になっていそうなアクティビティを再試行することによって、問題を再現することができます。では、遅延が発生する原因を特定できるように、スレッドダンプを取得し、CPU プロファイラーを実行します。

3. 問題を解決するためのコードを変更します

DEBUG ログ、スレッドダンプ、および CPU プロファイラーの出力を収集しました。これにより、根本的原因を断定するための十分な情報があります。長期実行 JCR EventListener/EventConsumer を示すログメッセージのサンプルについては [2] を参照してください。

結果に基づいて、次のいずれかが表示されます。

カスタム JCR EventListener にバグがあります。問題を解決するためにコードを最適化します。
コンテンツの蓄積が大量になると、カスタムまたはボックスからの JCR が低速になります。
問題を解決するために、不要になった関連コンテンツを削除します：
1. CRX エクスプローラー http://host:port/crx/explorer/index.jsp に移動します。（CQ 5.4 以前のバージョンにおいては /crx/index.jsp）に移動します。
2. 「Content Explorer」を開き、クリーンアップするコンテンツパスを参照します。
3. 削除したいツリーのトップのノードを右クリックして、「再帰的に削除する」を選択します。
4. プレスキャンの無効化と実行
ボックス外 JCR イベントリスナーの問題ー AEM（CQ）サポートにご連絡ください。

[1] 関連エラーメッセージ

07.04.2010 11:05:24 *WARN * ObservationDispatcher: More than 200000 events in the queue (ObservationDispatcher.java, line 228)
java.lang.Exception: Stack Trace
at org.apache.jackrabbit.core.observation.ObservationDispatcher.dispatchEvents(ObservationDispatcher.java:228)
at org.apache.jackrabbit.core.observation.EventStateCollection.dispatch(EventStateCollection.java:465)
at org.apache.jackrabbit.core.state.SharedItemStateManager$Update.end(SharedItemStateManager.java:763)
at org.apache.jackrabbit.core.state.SharedItemStateManager.update(SharedItemStateManager.java:1109)
at org.apache.jackrabbit.core.state.LocalItemStateManager.update(LocalItemStateManager.java:351)
at org.apache.jackrabbit.core.state.XAItemStateManager.update(XAItemStateManager.java:354)
at org.apache.jackrabbit.core.state.LocalItemStateManager.update(LocalItemStateManager.java:326)
at org.apache.jackrabbit.core.state.SessionItemStateManager.update(SessionItemStateManager.java:331)
at org.apache.jackrabbit.core.ItemImpl.save(ItemImpl.java:1124)
at org.apache.jackrabbit.core.SessionImpl.save(SessionImpl.java:919)
at com.day.jcr.vault.fs.io.AutoSave.save(AutoSave.java:114)
at com.day.jcr.vault.fs.io.Importer.commit(Importer.java:677)

[2] EventConsumer DEBUG ログメッセージのサンプル

25.11.2013 00:00:11.115 *DEBUG* [ObservationManager] org.apache.jackrabbit.core.observation.EventConsumer listener com.day.cq.rewriter.linkchecker.impl.LinkInfoStorageImpl processed events in 15250 ms.
25.11.2013 00:01:26.859 *DEBUG* [ObservationManager] org.apache.jackrabbit.core.observation.EventConsumer listener com.day.cq.rewriter.linkchecker.impl.LinkInfoStorageImpl processed events in 74077 ms.
25.11.2013 00:02:30.569 *DEBUG* [ObservationManager] org.apache.jackrabbit.core.observation.EventConsumer listener com.day.cq.rewriter.linkchecker.impl.LinkInfoStorageImpl processed events in 49786 ms.

追加情報

このエラーは、通常、JCR イベントリスナーが原因で発生します。特定の JCR イベントリスナーが、何らかの理由でイベントの不適切な処理をしていたり、その処理速度が過度に低下していることがあります。

JCR イベントリスナーの背景情報については、こちらを参照してください。

アカウントにログイン