Luxor各種ログ
Luxorサーバに出力されるログ
検索時やインデックス作成中に異常が発生した場合、ログが出力されます。Luxorのログ取得に関する設定はlog4j.xmlにて行います。log4j.xmlにてログの出力形式や出力レベルを変更することが可能です。
Luxor Ver.2.1.1以降では、log4j.xmlの設定にデフォルトで出力するログのプライオリティを「error」から「info」に変更しました。
ログレベルの変更による影響対象は「/var/log/luxor/luxor.log」です。
ログファイル名 | 説明 | |
---|---|---|
Luxorサーバ | /var/log/luxor/solr.log | Apache Projectで開発されている検索エンジンSolrに関連するログが出力される。 |
Luxorサーバ | /var/log/luxor/luxor.log | Luxorの動作中に発生したログが出力される。全文検索実施中のログ、インデックス作成のログや最適化処理などのログ情報はluxor.logに出力される。 |
制限・注意事項
log4j.xmlの設定では出力するログのプライオリティをデフォルトで「info」に変更したことで、 該当バージョンから、前のバージョンよりログ出力量が多くなります。 ログ出力量が気になる場合、下記のように設定を変更してください。
変更
<category name="jp.co.dreamarts" additivity="false">
<priority value="error" />
<appender-ref ref="LUXOR_LOG" />
</category>
追加:
<category name="jp.co.dreamarts.solr.reminder.LuxorOptimizeReminder" additivity="false">
<priority value="info" />
<appender-ref ref="LUXOR_LOG" />
</category>
製品APサーバに出力されるログ
ログファイル名 | |
---|---|
INSUITE® APサーバ | /home/DreamArts/logs/luxor/luxor_log.YYYYMMDD |
Sm@rtDB APサーバ | /var/logs/hibiki/hibiki.log.YYYYMMDD |
Tomcatに関連するログ
TomcatはLuxorで利用されるサードパティのアプリケーションサーバとなります。本章では、Luxor運用中のTomcat関連ログを説明します。ログの詳細情報、または関連ログのレベル設定に関しては、Tomcatの公式サイトを参照してください。
Tomcatに関連するログ
Luxorサーバ | 説明 |
---|---|
/usr/local/luxor/tomcat/logs/catalina.out | catalina.outにはTomcatのログが出力されます。コンソールと同じ内容が出力される。サービスの起動時/停止時にTomcatに関する情報も含まれる。 |
/usr/local/luxor/tomcat/logs/catalina.YYYY-MM-DD.log | catalina.YYYY-MM-DD.logには、Tomcatのログが出力され、コンソールと同じ内容が出力される。サービス起動時/停止時にTomcatに関する情報も含まれる。 |
/usr/local/luxor/tomcat/logs/localhost.YYYY-MM-DD.log | localhost.YYYY-MM-DD.logには、Tomcat内で実行するウェブアプリケーションのログが出力される。サービスの起動時/停止時に(Wagbyが内部で利用しているミドルウェアである)SpringやQuartz(ジョブ実行用)のログが出力される。 |
/usr/local/luxor/tomcat/logs/manager.YYYYY-MM-DD.log | manager.YYYYY-MM-DD.logには、Tomcatに標準で含まれている/managerへアクセスした際のログが出力される。 |
/usr/local/luxor/tomcat/logs/host-manager.YYYY-MM-DD.log | host-manager.YYYY-MM-DD.logには、Tomcatに標準で含まれている/host-managerへアクセスした際のログが出力される。 |
/usr/local/luxor/tomcat/logs/localhost_access_log.YYYY-MM-DD.txt | localhost_access_log.YYYY-MM-DD.txtには、主にアクセスの時間、IPアドレス、アクセス先等の関連情報が出力される。Tomcat出力されるすべてのHTTPリクエストのアクセスログが出力される。 |
各種ログの出力原因·出力例·対処法
各種ログの原因及び対処法を説明します。
[1] /var/log/luxor/luxor.logの出力例
[1-1] 出力例: 403 Forbidden on request URL
2011-06-01 14:24:46 Status line: HTTP/1.1 403 Forbidden on request URL: http://localhost/cgi-bin/sr_luxor_permit_check.cgi, discard search result.org.apache/commons.httpclient.HttpException
原因:LuxorサーバからINSUITE®へのアクセス時のIP制限に抵触しています。LuxorサーバIPとして設定していないIPアドレスからアクセスがあった場合に発生します。
対処方法:Luxorのsetup.conf中のiseUrlの設定を見直してください。
[1-2] 出力例: java.io.IOException: No content exception 204.
2011-06-10 15:35:37 ERROR solr.LuxorUtils (LuxorUtils.java:384) can't download http://localhost/cgi-bin/sr_luxor_attach_download.cgi?attach=schedule:/insuite/schedule/201106/62/462/462-1.txt java.io.IOException: No content exception 204.
原因:LuxorがINSUITE®上の添付ファイルをダウンロードする際に、doccatコマンドの実行に失敗したことが原因です。doccatコマンドが処理する対象ファイルサイズの最大値を超えたファイルをダウンロードする場合などに発生します。
対処方法:doccatコマンドが処理する対象ファイルサイズの最大値を調整します。
doccatコマンドの設定については、『INSUITE®アプリケーション·アドミニストレーション·ガイド』の「doccat.conf」の記載を参照してください。
[1-3] 出力例: java.io.FileNotFoundException
2011-06-10 15:38:32 ERROR solr.LuxorUtils (LuxorUtils.java:384) can't download http://localhost/cgi-bin/sr_luxor_attach_download.cgi?attach=schedule:/insuite/schedule/201106/62/462/462-1.txt java.io.FileNotFoundException: http://localhost/cgi-bin/sr_luxor_attach_download.cgi?attach=schedule:/insuite/schedule/201106/62/462/462-1.txt
原因:ユーザが添付ファイルを伴うデータを登録した後、Luxorサーバは非同期処理にてINSUITE®から添付ファイルをダウンロードします。その間にユーザがデータを削除した場合は発生する可能性があります。
例えば、何らかの障害より、NFS上のファイルの実体が存在せず、DB上にはファイルの情報が存在する、といったような不整合が既に生じていた場合に発生するエラーとなります。
対処方法:特に対処不要です。
[1-4] 出力例: java.io.FileNotFoundException
2011-06-02 11:41:37 ERROR solr.LuxorUtils (LuxorUtils.java:377) can't download http://localhost:10080/solr/cgi-bin/sr_luxor_attach_download.cgi?attach=attach_404 java.io.FileNotFoundException : http://localhost:10080/solr/cgi-bin/sr_luxor_attach_download.gi?attach=attach_404
原因:添付ファイルのダウンロードが失敗した場合に出力されます。原因は三つ可能性があります。
1)添付ファイルの実体がINSUITE®上から削除された(INSUITE®が404を返した)。
2)URL間違い
3)INSUITE®の内部エラー。
対処方法:添付ファイルの実体がINSUITE®上から削除された場合は、問題ありません。
[1-5] 出力例: ERROR filter.BasicAuthFilter
2011-06-02 11:40:30 ERROR filter.BasicAuthFilter (BasicAuthFilter.java:41) AuthFailure:
原因:Basic認証の設定が正しくありません。
対処方法:Luxorサーバsetup.conf中のiseApacheUser、iseApachePassの設定を見直してください。
[1-6] 出力例: ERROR solr.HttpUtilsEx
2011-06-02 15:02:16 ERROR solr.HttpUtilsEx (HttpUtilsEx.ava:137) Status line: HTTP/1.1 404 Not Found on request URL: http://localhost:10080/solr/cgi-bin/sr_luxor_permit_check.cgi、 discard search result.2011-06-02 15:02:28 ERROR filter.ostCheckFilterINSUITECallback (PostCheckFilterINSUITECallback.ava:113) can't access http://localhost:10080/solr/cgi-bin/sr_luxor_permit_check.cgi
原因:LuxorからINSUITE®へ何らかの原因でアクセスできなかった場合、該当のエラーが出力されます。
対処方法:該当のエラーが1回のみ出力された場合、おそらくは一時的なネットワーク、またはサーバの負荷によるものと考えられますので、対処は不要です。該当のエラーが頻繁に出力される場合、INSUITE®またはLuxorの設定に誤りがある可能性が考えられます。アクセス不能なIPに設定されているかを、Luxorサーバsetup.onf中のiseUrlの設定を見直してください。
[1-7] 出力例: java.net.SocketTimeoutException: Read timed out
2012-01-24 23:59:29 ERROR solr.LuxorUtils (LuxorUtils.java:402) can't download http://127.0.0.1/cgi-bin/sr_luxor_attach_download.cgi?attach=schedule:/insuite/schedule/201201/81/81/81-1.txt java.net.SocketTimeoutException: Read timed out at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(Unknown Source) at java.io.BufferedInputStream.fill(Unknown Source) at java.io.BufferedInputStream.read1(Unknown Source) at java.io.BufferedInputStream.read(Unknown Source)
原因:LuxorからINSUITE®への通信がタイムアウトした場合に出力されます。
対処方法:頻繁に発生する場合、LuxorとINSUITE®間のネットワーク設定を見直してください。また、INSUITE®からの添付ファイルダウンロードが何らかの理由で時間を要する場合に発生することがあります。
[1-8] 出力例: java.net.ConnectException: Connection refused
2011-04-25 00:08:03 ERROR solr.LuxorUtils (LuxorUtils.java:402) can't download http://127.0.0.1/cgi-bin/sr_luxor_attach_download.cgi?attach=schedule:/insuite/schedule/201201/81/81/81-1.txt java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.PlainSocketImpl.doConnect(Unknown Source) at java.net.PlainSocketImpl.connectToAddress(Unknown Source) at java.net.PlainSocketImpl.connect(Unknown Source)
原因:LuxorからINSUITE®へのhttp接続(https接続)ができなかった場合に出力されます。
対処方法:INSUITE®サービスが一時停止したか、ネットワークが不通となっていないかをご確認ください。
[1-9] 出力例: LuxorUpdateThread
2017-01-10 08:53:06,329 INFO [LuxorUpdateThread (PRIMARY)] solr.LuxorComponent$StatisticsInfo (LuxorComponent.java:468) : [COUNT] core[document_item] method[Delete] reached : 10334000 2017-01-10 08:53:07,525 INFO [LuxorUpdateThread (PRIMARY)] solr.LuxorComponent$StatisticsInfo (LuxorComponent.java:468) : [COUNT] core[document_item] method[Add] reached : 15176000 2017-01-10 08:54:39,514 INFO [LuxorUpdateThread (PRIMARY)] solr.LuxorComponent$StatisticsInfo (LuxorComponent.java:468) : [COUNT] core[document_item] method[Delete] reached : 10335000 2017-01-10 08:55:11,433 INFO [LuxorUpdateThread (PRIMARY)] solr.LuxorComponent$StatisticsInfo (LuxorComponent.java:468) : [COUNT] core[document_item] method[Add] reached : 15177000 2017-01-10 08:56:12,745 INFO [LuxorUpdateThread (PRIMARY)] solr.LuxorComponent$StatisticsInfo (LuxorComponent.java:468) : [COUNT] core[document_item] method[Delete] reached : 10336000 2017-01-10 08:57:14,520 INFO [LuxorUpdateThread (PRIMARY)] solr.LuxorComponent$StatisticsInfo (LuxorComponent.java:468) : [COUNT] core[document_item] method[Add] reached : 15178000 2017-01-10 09:05:23,630 INFO [LuxorUpdateThread (PRIMARY)] solr.LuxorComponent$StatisticsInfo (LuxorComponent.java:468) : [COUNT] core[document_item] method[Delete] reached : 10337000
原因:Sm@rtDBで文書新規と更新する際に出力されます。インデックス再作成する際、まず古いインデックスを削除してから、新規作成との流れなので、検索サーバのSWAP使用率が上がるのは正常事象と考えられます。
対処方法:特に対処不要です。
[1-10] 出力例: failover.FailOverConfig (FailOverConfig.java:173) No setting of this server found, use OFF mode.
2017-05-12 14:19:38 WARN failover.FailOverConfig (FailOverConfig.java:173) No setting of this server found, use OFF mode. (use either nc02pins-srch02-t.nscc-t.nssmc-t.com-t or 127.0.0.1 for this server) 2017-05-12 14:19:38 INFO solr.LuxorUpdateThread (LuxorUpdateThread.java:54) LuxorUpdateThread failOverMode is OFF, LuxorUpdateThread will not be started.
原因:ネットワークの設定と関連しているログとなります。
対処方法:Luxorサーバ上のhostnameを修正し、SolrTomcatを再起動して問題が再発するかをご確認ください。
[1-11] 出力例: error occured while processing file
2017-06-22 14:57:13 /home/DreamArts/cgi-bin/sr_luxor_attach_download.cgi: error occured while processing file (/home/DreamArts/data/ns_board/90/1590/0002) error is below : warning: /home/DreamArts/data/ns_board/90/1590/0002 appears to use backslashes as path separators
原因:添付ファイルインデックス作成失敗のログです。作成失敗のため、インデックスはまだ作成されていません。
対処方法:クライアントの画面操作より、該当データを再保存して、インデックス再作成させてください。その後、検索結果に表示されるかをご確認ください。
[1-12] 出力例: Connection refused
2017-06-22 15:17:05,445 INFO [QuorumPeer[myid=3]/0:0:017-06-22 15:17:05,444 WARN [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:11080] quorum.QuorumCnxManager (QuorumCnxManager.java:588) : Cannot open channel to 2 at election address /10.2.2.64:11082 java.net.ConnectException: Connection refused (Connection refused) at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:589) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:562) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxManager.java:614) at org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:843) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:913)
原因:ZooKeeper関連ログとなります。複数台サーバ構成の場合、一台のみが先に起動されるとき、該当ログが頻繁に出力されます。
対処方法:影響を与えるログではありません。全体の半数台以上のサーバが起動されると、出力されなくなります。
[1-13] 出力例: Connection broken for id 1, my id = 2, error = java.io.EOFException
2017-06-22 15:49:42,680 WARN [RecvWorker:1] quorum.QuorumCnxManager$RecvWorker (QuorumCnxManager.java:1028) : Connection broken for id 1, my id = 2, error = java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:1013) 2017-06-22 15:49:42,682 WARN [RecvWorker:1] quorum.QuorumCnxManager$RecvWorker (QuorumCnxManager.java:1031) : Interrupting SendWorker 2017-06-22 15:49:42,683 WARN [SendWorker:1] quorum.QuorumCnxManager$SendWorker (QuorumCnxManager.java:944) : Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2088) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:1097) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$700(QuorumCnxManager.java:74) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:932) 2017-06-22 15:49:42,683 WARN [SendWorker:1] quorum.QuorumCnxManager$SendWorker (QuorumCnxManager.java:954) : Send worker leaving thread
原因:ZooKeeper関連ログとなります。複数台サーバ構成の場合、特定サーバのサービスが何らかの原因によりダウンし、ZooKeeperサービスが動作不能となった場合、ダウンしていない他のZooKeeperノードに該当情報を提示します。
例えば、「Connection broken for id 1, my id = 2,」では、myid=1に設定しているノードはサービス落ちている、本ノードのmyidは2であると表します。
対処方法:ダウンしたサービスを再起動することで該当ログが解消されます。
[1-14] 出力例: Failed to connect
2017-06-22 10:16:43,783 WARN [ActiveMQ Task-5] failover.FailoverTransport (FailoverTransport.java:1100) : Failed to connect to [tcp://127.0.0.1:12082, tcp://127.0.0.1:12083, tcp://127.0.0.1:12084] after: 10 attempt(s) continuing to retry.
原因:ActiveMQ関連のログとなります。該当ログが出力される時、ActiveMQサービスが利用不可となり、Luxorのキューはリクエストを受けなくなります。この場合、受付できないリクエストはSm@rtDBとINSUITE®それぞれのキューに溜まります。
例えば、Luxor三台構成で、ActiveMQサービスはそれぞれ127.0.0.1:12082、127.0.0.1:12083、tcp://127.0.0.1:12084となります。二台以上がサービス停止していると、ActiveMQクラスタは利用不可となります。
対処方法:Solr用のTomcatサービスを再起動してください。
[1-15] 出力例: Promoted to master
2017-06-22 15:11:39,916 INFO [ActiveMQThread-EventThread] util.Log$class (Log.scala:93) : Promoted to master 2017-06-22 15:11:39,951 INFO [ActiveMQ BrokerService[luxorReqQueue] Task-3] util.Log$class (Log.scala:93) : Using the pure java LevelDB implementation. 2017-06-22 15:11:40,307 INFO [ActiveMQ BrokerService[luxorReqQueue] Task-4] util.Log$class (Log.scala:93) : Master started: tcp://127.0.0.1:63332 2017-06-22 15:11:41,311 WARN [ActiveMQ BrokerService[luxorReqQueue] Task-3] util.Log$class (Log.scala:75) : Store update waiting on 1 replica(s) to catch up to log position 55. 2017-06-22 15:11:42,313 WARN [ActiveMQ BrokerService[luxorReqQueue] Task-3] util.Log$class (Log.scala:75) : Store update waiting on 1 replica(s) to catch up to log position 55. 2017-06-22 15:11:43,318 WARN [ActiveMQ BrokerService[luxorReqQueue] Task-3] util.Log$class (Log.scala:75) : Store update waiting on 1 replica(s) to catch up to log position 55. 2017-06-22 15:11:44,322 WARN [ActiveMQ BrokerService[luxorReqQueue] Task-3] util.Log$class (Log.scala:75) : Store update waiting on 1 replica(s) to catch up to log position 55. 2017-06-22 15:11:45,324 WARN [ActiveMQ BrokerService[luxorReqQueue] Task-3] util.Log$class (Log.scala:75) : Store update waiting on 1 replica(s) to catch up to log position 55. 2017-06-22 15:11:46,329 WARN [ActiveMQ BrokerService[luxorReqQueue] Task-3] util.Log$class (Log.scala:75) : Store update waiting on 1 replica(s) to catch up to log position 55. 2017-06-22 15:11:47,333 WARN [ActiveMQ BrokerService[luxorReqQueue] Task-3] util.Log$class (Log.scala:75) : Store update waiting on 1 replica(s) to catch up to log position 55. 2017-06-22 15:11:48,336 WARN [ActiveMQ BrokerService[luxorReqQueue] Task-3] util.Log$class (Log.scala:75) : Store update waiting on 1 replica(s) to catch up to log position 55. 2017-06-22 15:11:49,342 WARN [ActiveMQ BrokerService[luxorReqQueue] Task-3] util.Log$class (Log.scala:75) : Store update waiting on 1 replica(s) to catch up to log position 55. 2017-06-22 15:11:50,342 WARN [ActiveMQ BrokerService[luxorReqQueue] Task-3] util.Log$class (Log.scala:75) : Store update waiting on 1 replica(s) to catch up to log position 55. 2017-06-22 15:11:50,667 INFO [hawtdispatch-DEFAULT-2] util.Log$class (Log.scala:93) : Slave has connected: cee2dc80-3a37-4382-958b-4b9f20c82f26 2017-06-22 15:11:50,746 INFO [hawtdispatch-DEFAULT-2] util.Log$class (Log.scala:93) : Slave has now caught up: cee2dc80-3a37-4382-958b-4b9f20c82f26 2017-06-22 15:11:50,796 INFO [ActiveMQThread] broker.BrokerService (BrokerService.java:734) : Apache ActiveMQ 5.14.5 (luxorReqQueue, ID:hibodeMacBook-Pro.local-53219-1498115197499-2:1) is starting 2017-06-22 15:11:55,898 INFO [ActiveMQThread] transport.TransportServerThreadSupport (TransportServerThreadSupport.java:69) : Listening for connections at: tcp://hibodeMacBook-Pro.local:12083?maximumConnections=1000&wireFormat.maxFrameSize=104857600 2017-06-22 15:11:55,898 INFO [ActiveMQThread] broker.TransportConnector (TransportConnector.java:263) : Connector openwire started 2017-06-22 15:11:55,899 INFO [ActiveMQThread] broker.BrokerService (BrokerService.java:761) : Apache ActiveMQ 5.14.5 (luxorReqQueue, ID:hibodeMacBook-Pro.local-53219-1498115197499-2:1) started 2017-06-22 15:11:55,899 INFO [ActiveMQThread] broker.BrokerService (BrokerService.java:762) : For help or more information please see: http://activemq.apache.org
原因:ActiveMQ関連のログとなります。複数台サーバ構成で、ActiveMQが何らかの原因によりダウンした場合、マスタにあたるリーダActiveMQを自動的に再選出します。選出する際にmasterと選ばれたノード(サーバ)に該当ログが出力されます。
対処方法:正常系ログのため、対処不要です。
[1-16] 出力例: Slave requested
2017-06-22 15:11:50,709 INFO [hawtdispatch-DEFAULT-3] util.Log$class (Log.scala:93) : Slave skipping download of: log/0000000000000000.log
2017-06-22 15:11:50,713 INFO [hawtdispatch-DEFAULT-3] util.Log$class (Log.scala:93) : Slave requested : 0000000000000037.index/MANIFEST-000026
2017-06-22 15:11:50,715 INFO [hawtdispatch-DEFAULT-3] util.Log$class (Log.scala:93) : Slave requested: 0000000000000037.index/CURRENT
2017-06-22 15:11:50,716 INFO [hawtdispatch-DEFAULT-3] util.Log$class (Log.scala:93) : Slave requested: 0000000000000037.index/000029.sst
2017-06-22 15:11:50,716 INFO [hawtdispatch-DEFAULT-3] util.Log$class (Log.scala:93) : Slave requested: 0000000000000037.index/000028.log
2017-06-22 15:11:50,731 INFO [hawtdispatch-DEFAULT-3] util.Log$class (Log.scala:93) : Attaching... Downloaded 0.41/1.88 kb and 1/4 files
2017-06-22 15:11:50,731 INFO [hawtdispatch-DEFAULT-3] util.Log$class (Log.scala:93) : Attaching... Downloaded 0.43/1.88 kb and 2/4 files
2017-06-22 15:11:50,732 INFO [hawtdispatch-DEFAULT-3] util.Log$class (Log.scala:93) : Attaching... Downloaded 1.19/1.88 kb and 3/4 files
2017-06-22 15:11:50,733 INFO [hawtdispatch-DEFAULT-3] util.Log$class (Log.scala:93) : Attaching... Downloaded 1.88/1.88 kb and 4/4 files
2017-06-22 15:11:50,734 INFO [hawtdispatch-DEFAULT-3] util.Log$class (Log.scala:93) : Attached
2017-06-22 15:11:50,734 INFO [hawtdispatch-DEFAULT-3] util.Log$class (Log.scala:93) : Attached
原因:ActiveMQ関連のログとなります。複数台サーバ構成の場合、ActiveMQが何らかの原因によりダウンした場合、マスタにあたるリーダActiveMQを自動的に再選出します。選出する際にslaveと選ばれたノード(サーバ)に該当ログが出力されます。
対処方法:正常系ログのため、対処不要です。
[1-17] 出力例:Error Occurred When Producer Sending Message To ActiveMQ
javax.jms.JMSException: COMMIT FAILED
2017-12-18 13:33:14,694 ERROR [catalina-exec-5] solr.LuxorQueueServlet (LuxorQueueServlet.java:99) : Error Occurred When Producer Sending Message To ActiveMQ
javax.jms.JMSException: COMMIT FAILED: Transaction marked rollback only xaErrorCode:100
at org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:54)
at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1399)
at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1428)
at org.apache.activemq.TransactionContext.commit(TransactionContext.java:330)
at org.apache.activemq.ActiveMQSession.commit(ActiveMQSession.java:582)
at jp.co.dreamarts.solr.LuxorQueueServlet.doExecute(LuxorQueueServlet.java:87)
at jp.co.dreamarts.solr.LuxorQueueServlet.doPost(LuxorQueueServlet.java:54)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:661)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at filters.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:123)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:364)
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:305)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at jp.co.dreamarts.insuite.system.filter.IPCheckFilter.doFilter(IPCheckFilter.java:55)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:650)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:803)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:790)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1459)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)
Caused by: javax.transaction.xa.XAException: COMMIT FAILED: Transaction marked rollback only xaErrorCode:100
at org.apache.activemq.transaction.Transaction.newXAException(Transaction.java:212)
at org.apache.activemq.transaction.Transaction.prePrepare(Transaction.java:115)
at org.apache.activemq.transaction.LocalTransaction.commit(LocalTransaction.java:54)
at org.apache.activemq.broker.TransactionBroker.commitTransaction(TransactionBroker.java:252)
at org.apache.activemq.broker.MutableBrokerFilter.commitTransaction(MutableBrokerFilter.java:118)
at org.apache.activemq.broker.TransportConnection.processCommitTransactionOnePhase(TransportConnection.java:538)
at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:100)
at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:336)
at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:200)
at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:125)
at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:301)
at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:233)
at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:215)
... 1 more
Caused by: javax.jms.TransactionRolledBackException: COMMIT FAILED: Transaction marked rollback only xaErrorCode:100
at org.apache.activemq.transaction.Transaction.prePrepare(Transaction.java:116)
... 14 more
原因:ActiveMQで保存しているデータ量が、activemq.xmlの設定"storeUsage"に記載しているファイルサイズの上限値を超過している場合、INSUITE及びSm@rtDBによりインデックスを新規作成する際、該当ログが出力されます。リクエストがActiveMQに保存できない状態になっています。
対処方法:ActiveMQでは処理待ちのリクエストを受け取り、受け取ったリクエストはサーバ上にファイル形式で保存されます。該当ファイルのサイズが上限値"storeUsage"を超過した場合、リクエストの受け取りが停止されます。上限値のデフォルトは1GBです。
順次リクエストが進むことで、リクエストの受付は再開されます。また、受け付けられなかったリクエストは、INSUITE・Sm@rtDBで持っているため、データの不整合は発生しません。
該当ログが出力される場合、activemq.xmlの設定の"storeUsage"を大きく調整してください。「ActiveMQサイズの変更手順例」の詳細に関しては、「メッセージキューイング処理」の記載を参照してください。
[1-18] 出力例:Invalid configuration, only one server specified**
2017-12-20 09:21:30,027 ERROR [ZookeeperThread] quorum.QuorumPeerConfig (QuorumPeerConfig.java:345) : Invalid configuration, only one server specified (ignoring)
原因:Luxorを単体で構築した場合、Luxorを起動する際に出力されるログとなります。
対処方法:Luxorサーバを単体で構築した場合におけるZooKeeperの仕様となります。Luxorの利用に影響はありません。
[1-19] 出力例:Failed to get collections status
2018-06-22 16:17:37,675 WARN [SolrStatusWatcher] solr.SolrStatusWatcher (SolrStatusWatcher.java:67) : Failed to get collections status. Could not find collection : board. May be you need to upload the config to zookeeper and create the collections by 'setup.sh'.
原因:Luxorの起動が完全に成功する前、全てのCoreが利用可であるかのチェックが入っています。新規導入する場合、LuxorのCoreがまだ作成していないうちに該当ログが出力されます。
対処方法:設定ファイルをUploadし、全Coreの作成成功後、該当ログは出力されなくなります。
[1-20] 出力例:Could not find a healthy node to handle the request.
2018-06-22 16:37:42,921 WARN [http-nio-10082-exec-2] solr.AboutServlet (AboutServlet.java:205) : Could not find a healthy node to handle the request. No boot completely, please wait for a moment.
原因:コレクションがすべて起動されていないうち、About管理画面にアクセスする際に出力される提示メッセージとなります。
対処方法:暫く待って頂いてから再度About管理画面にアクセスすると、該当ログは出力されなくなります。
[1-21] 出力例:Unexpected exception causing shutdown while sock still open
java.io.EOFException**
2017-12-20 09:36:32,013 ERROR [LearnerHandler-/10.2.2.65:41103] quorum.LearnerHandler (LearnerHandler.java:648) : Unexpected exception causing shutdown while sock still open
java.io.EOFException
at java.io.DataInputStream.readInt(DataInputStream.java:392)
at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
at org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83)
at org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:559)
2017-12-20 09:40:30,937 ERROR [LearnerHandler-/10.2.2.65:54067] quorum.LearnerHandler (LearnerHandler.java:648) : Unexpected exception causing shutdown while sock still open
java.net.SocketException: Connection reset
at java.net.SocketInputStream.read(SocketInputStream.java:210)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
at java.io.DataInputStream.readInt(DataInputStream.java:387)
at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
at org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83)
at org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:559)
原因:Cluster内で、落ちているサーバが見つかったことを示す、通常のログです。通常のログです。複数台構築の場合、一つサーバが落ちると、生きているLuxorサーバ(Active)にて該当ログが出力されます。
対処方法: 落ちているサーバを起動させる必要があります。
[1-22] 出力例:Error in thread 'ActiveMQ BrokerService
2017-12-20 09:51:35,369 ERROR [ActiveMQ BrokerService[luxorReqQueue] Task-3] thread.TaskRunnerFactory$1$1 (TaskRunnerFactory.java:202) : Error in thread 'ActiveMQ BrokerService[luxorReqQueue] Task-3'
java.lang.Error: org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /activemq/leveldb-stores/00000000012
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1155)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /activemq/leveldb-stores/00000000012
at org.apache.zookeeper.KeeperException.create(KeeperException.java:99)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.setData(ZooKeeper.java:1327)
at org.linkedin.zookeeper.client.ZooKeeperImpl.setData(ZooKeeperImpl.java:239)
at org.linkedin.zookeeper.client.AbstractZooKeeper.setData(AbstractZooKeeper.java:261)
at org.apache.activemq.leveldb.replicated.groups.ZooKeeperGroup.liftedTree1$1(ZooKeeperGroup.scala:146)
at org.apache.activemq.leveldb.replicated.groups.ZooKeeperGroup.update(ZooKeeperGroup.scala:145)
at org.apache.activemq.leveldb.replicated.groups.ClusteredSingleton.join(ClusteredSingleton.scala:212)
at org.apache.activemq.leveldb.replicated.MasterElector.update(MasterElector.scala:90)
at org.apache.activemq.leveldb.replicated.MasterElector$change_listener$.changed(MasterElector.scala:243)
at org.apache.activemq.leveldb.replicated.MasterElector$change_listener$$anonfun$changed$2.apply$mcVI$sp(MasterElector.scala:205)
at org.apache.activemq.leveldb.replicated.ElectingLevelDBStore$$anonfun$start_master$2.apply$mcV$sp(ElectingLevelDBStore.scala:235)
at org.fusesource.hawtdispatch.package$$anon$4.run(hawtdispatch.scala:330)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
... 2 more
2017-12-20 09:51:35,833 ERROR [ActiveMQ BrokerService[luxorReqQueue] Task-2] thread.TaskRunnerFactory$1$1 (TaskRunnerFactory.java:202) : Error in thread 'ActiveMQ BrokerService[luxorReqQueue] Task-2'
java.lang.IllegalStateException: Store replication stopped
at org.apache.activemq.leveldb.replicated.MasterLevelDBStore.wal_sync_to(MasterLevelDBStore.scala:432)
at org.apache.activemq.leveldb.replicated.MasterLevelDBStore.doStart(MasterLevelDBStore.scala:113)
at org.apache.activemq.util.ServiceSupport.start(ServiceSupport.java:55)
at org.apache.activemq.leveldb.replicated.ElectingLevelDBStore$$anonfun$start_master$1.apply$mcV$sp(ElectingLevelDBStore.scala:230)
at org.fusesource.hawtdispatch.package$$anon$4.run(hawtdispatch.scala:330)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
原因:Cluster内で、新しいleaderサーバを選択する時の通常ログです。複数台構築の場合、ActiveMQのleaderサーバが落ちると、生きているLuxorサーバ(Active)は該当ログが出力されます。
対処方法:落ちているサーバを起動させる必要があります。
[2] /home/DreamArts/logs/luxor/luxor_log.YYYYMMDDの出力例
[2-1] 出力例: ERROR: 500 Can't connect
19:30:25 ERROR: 500 Can't connect to 127.0.0.1:10080 (Timeout) request url=http://127.0.0.1:10080/solr/select
原因:INSUITE® APサーバのLuxorサーバIP、ポート番号を指定するパラメータが正しくない可能性があります。
対処方法:INSUITE®の設定ファイルdomain.datのluxor_ip(デフォルト:127.0.0.1)、luxor_port(デフォルト:10080)パラメータ設定を見直してください。
[2-2] 出力例: ERROR: 404 Not Found
19:36:54 ERROR: 404 Not Found request url=http://127.0.0.1:10080/solr_dir/select
原因:INSUITE®からLuxorサーバへのアクセスに失敗しています。INSUITE® APサーバのLuxor APIを指定するパラメータが正しくない可能性があります。
対処方法:INSUITE®の設定ファイルdomain.datにて、luxor_rdir(デフォルト:/solr)パラメータの設定を見直してください。
[2-3] 出力例: ERROR: 401 Unauthorized
19:36:54 ERROR: 401 Unauthorized request url=http://127.0.0.1:10080/solr_dir/select
原因:INSUITE®からLuxorへのアクセス時のBasic認証に失敗しています。INSUITE® APサーバのBasic認証のON/OFFまたはアカウント、パスワードの値がLuxor APサーバの設定と異なることが原因です。
対処方法:Basic認証のON/OFFは INSUITE® APサーバ、Luxorサーバで同じ設定に合わせる必要があります。また、アカウントとパスワードの値もINSUITE® APサーバ、Luxorサーバで同じ値となる必要があります。
[2-4] 出力例: doccat failed
home/DreamArts/cgi-bin/sr_luxor_attach_download.cgi : doccat failed
原因:LuxorがINSUITE®上の添付ファイルをダウンロードする際、コマンドdoccatの実行に失敗したことが原因です。doccatが処理する対象ファイルサイズの最大値を超えたファイルをダウンロードする場合などに発生します。
対処方法:頻繁に発生する場合、doccatの設定を見直してください。doccatの詳細については、『INSUITE®アプリケーション·アドミニストレーション·ガイド』の「doccat.conf」を参照してください。
[3] /var/logs/hibiki/hibiki.log.YYYYMMDDの出力例
[3-1] 出力例: java.net.NoRouteToHostException: No route to host
[3-1] java.net.NoRouteToHostException: No route to host
2012-08-07 11:15:14,894 ERROR luxor.LuxorQueue (LuxorQueue.java:167) : Failed to add luxor queue. key=0,10237; type=Binder; qdate=1346205882414; IndexParameter : [ indexType=Binder; indexOption=Option.INSERT; indexArgs=10237; indexKey=0,10237 ]; java.net.NoRouteToHostException: No route to host at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351) at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213) at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366) at java.net.Socket.connect(Socket.java:529) at java.net.Socket.connect(Socket.java:478) at java.net.Socket.\
原因:Luxorサーバに接続できず、インデックスが作成できないことが原因です。Luxorサーバが起動していない可能性があります。
対処方法:Luxorサーバが起動しているかをご確認ください。
[3-2] 出力例: Can't connection to luxor server.
2012-08-07 13:50:28,294 ERROR luxor.LuxorClient (LuxorClient.java:280) : Can't connection to luxor server. URL: http://10.2.2.147:10080/solr/update_luxor. Parameters: ["function":"insert","component":"binder","id":"10238","title":"binder_20120807","gid":"2000000","reg_date":"2012-08-07T04:50:22Z","upd_date":"2012-08-07T04:50:22Z","reg_account":"1000011","upd_account":"1000011","owner":"1000011","public":"true","allow":"","parent_cabinet_id":"0","document_search_type":"speed","binder_id":"10238","binder_type":"binder","permit_reader":"FormDesigner","permit_reader":"DocManager","permit_reader":"BinderReader","permit_reader":"DocRegAccount","basic_view":"true","validity_start":"","validity_end":"","content":"binder_20120807 binder_20120807"]. java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351) at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213) at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366) at java.net.Socket.connect(Socket.java:529) at java.net.Socket.connect(Socket.java:478) at java.net.Socket.
原因:Luxorサーバに接続できず、インデックスが作成できないことが原因です。LuxorサーバのTomcatが停止された可能性があります。
対処方法:LuxorサーバのTomcatを再起動してください。
[3-3] 出力例: ERROR reindexcmd.IndexRebuildService
(IndexRebuildService.java:854) : some error happended when send luxor add info to luxor server!
2012-08-07 13:11:04,604 FATAL impl.SmartDatabaseImpl (SmartDatabaseImpl.java:488) : Sorry, this operation is not supported yet. java.lang.Throwable at jp.co.dreamarts.insuite.smartcab.impl.SmartDatabaseImpl.get(SmartDatabaseImpl.java:488) at jp.co.dreamarts.insuite.smartcab.impl.SmartDatabaseImpl.get(SmartDatabaseImpl.java:386) at jp.co.dreamarts.insuite.smartcab.impl.SmartDatabaseImpl.get(SmartDatabaseImpl.java:320) at jp.co.dreamarts.insuite.smartcab.impl.SmartDatabaseImpl.get(SmartDatabaseImpl.java:299) at jp.co.dreamarts.insuite.smartcab.impl.SmartDatabaseImpl.get(SmartDatabaseImpl.java:290) at jp.co.dreamarts.hibiki.smartdb.luxor.impl.DocumentRequestCreator.update(DocumentRequestCreator.java:148) at jp.co.dreamarts.hibiki.smartdb.luxor.impl.DocumentRequestCreator.getLuxorRequests(DocumentRequestCreator.java:103) at jp.co.dreamarts.hibiki.smartdb.luxor.reindexcmd.IndexRebuildService.buildIndex(IndexRebuildService.java:791) at jp.co.dreamarts.hibiki.smartdb.luxor.reindexcmd.IndexRebuildCommand.execute(IndexRebuildCommand.java:397) at jp.co.dreamarts.hibiki.smartdb.tool.Tool.run(Tool.java:219) at jp.co.dreamarts.hibiki.smartdb.tool.Main.main(Main.java:337) 2012-08-07 18:22:30,362 ERROR reindexcmd.IndexRebuildService (IndexRebuildService.java:854) : some error happended when send luxor add info to luxor server! java.lang.NullPointerException at jp.co.dreamarts.hibiki.smartdb.api.server.ServerAPIDocument.
原因:full_text_search.xmlのcontinueWhenExecptionをfalseに設定し移行ツールを実行する時、移行データに異常があるとインデックスが作成できません。
対処方法:full_text_search.xmlにcontinueWhenExecptionをtrueに設定することで、異常データをスキップして移行ツールを続行できるようにします。異常データをスキップしたくない場合は、以上の発生しているデータを確認してください。
[3-4] 出力例: ERROR reindexcmd.IndexRebuildService(IndexRebuildService.java:816) : バインダID 10,226の文書ID 1に異常があるため、全文検索インデックスが作成できません。
2012-08-07 18:20:03,535 FATAL impl.SmartDatabaseImpl (SmartDatabaseImpl.java:488) : Sorry, this operation is not supported yet. java.lang.Throwable at jp.co.dreamarts.insuite.smartcab.impl.SmartDatabaseImpl.get(SmartDatabaseImpl.java:488) at jp.co.dreamarts.insuite.smartcab.impl.SmartDatabaseImpl.get(SmartDatabaseImpl.java:386) at jp.co.dreamarts.insuite.smartcab.impl.SmartDatabaseImpl.get(SmartDatabaseImpl.java:320) at jp.co.dreamarts.insuite.smartcab.impl.SmartDatabaseImpl.get(SmartDatabaseImpl.java:299) at jp.co.dreamarts.insuite.smartcab.impl.SmartDatabaseImpl.get(SmartDatabaseImpl.java:290) at jp.co.dreamarts.hibiki.smartdb.luxor.impl.DocumentRequestCreator.update(DocumentRequestCreator.java:148) at jp.co.dreamarts.hibiki.smartdb.luxor.impl.DocumentRequestCreator.getLuxorRequests(DocumentRequestCreator.java:103) at jp.co.dreamarts.hibiki.smartdb.luxor.reindexcmd.IndexRebuildService.buildIndex(IndexRebuildService.java:791) at jp.co.dreamarts.hibiki.smartdb.luxor.reindexcmd.IndexRebuildCommand.execute(IndexRebuildCommand.java:397) at jp.co.dreamarts.hibiki.smartdb.tool.Tool.run(Tool.java:219) at jp.co.dreamarts.hibiki.smartdb.tool.Main.main(Main.java:337) 2012-08-07 18:20:03,549 ERROR reindexcmd.IndexRebuildService (IndexRebuildService.java:816) : バインダID 10,226の文書ID 1に異常があるため、全文検索インデックスが作成できません。 java.lang.NullPointerException at jp.co.dreamarts.hibiki.smartdb.api.server.ServerAPIDocument.
原因:full_text_search.xmlにcontinueWhenExecptionをfalseに設定し、移行ツールを実行する時、移行データに異常があり、インデックスが作成できません。
対処方法:ログの内容に従って異常が発生しているデータを分析し、異常原因を対応してください。
[3-5] 出力例:ERROR dao.BinderDAO
2017-02-06 15:13:00,883 ERROR dao.BinderDAO (BinderDAO.java:1876) :
org.xml.sax.SAXParseException; lineNumber: 2; columnNumber: 67; Element type "extrainfomarts.hibiki.smartdb.hookpoints.DocumentActionHookPoints
" must be followed by either attribute specifications, ">" or "/>".
原因:バインダの定義ファイルextrainfo.xmlに誤りがある可能性があります。バインダインデックスを再作成時、バインダ定義をロードすると、該当エラーが出力されます。extrainfo.xmlファイルはAddon適用する際にも利用され、Addonによる編集ミスの可能性もあります。
対処方法:問題のあるバインダのextrainfo.xmlファイルを修正すれば、エラー解消できます。reindexコマンド実行画面にも上記と同様のログが出力されます。
[4] /var/log/luxor/solr.logの出力例
[4-1] 出力例: too many boolean clauses
binder_id:16375 OR binder_id:16376 OR binder_id:16377 OR binder_id:16378 OR binder_id:16379 OR binder_id:16380 OR binder_id:16381 OR binder_id:16382) AND ( (title:図面) OR (content:図面))': too many boolean clauses
Sm@rtDBのhibiki.logに以下のエラーログも同じです。エラー,2017/03/07 14:19:54,"2TIP tip1sap102 2TIP2100-E 2017-03-07 14:19:39,991 ERROR unifiedsearch.UnifiedSearch (UnifiedSearch.java:264) :doucment luxor-search failed.q:[component.q - {_document:_(binder_id:16394 OR binder_id:16396 OR binder_id:16397 OR ...
原因:Luxorで検索する時、検索条件が多すぎて処理失敗となります。Solrの制限事項です。
対処方法:Solrでは検索条件の指定数を制限しています。検索条件を減らしてください。全文検索画面では「対象キャビネット」を利用する場合、検索条件には全ての所属バインダIDを使ってしまう仕様で、全文検索画面の「対象キャビネット」の利用をしないことなどの運用回避が考えられます。
[4-2] 出力例: common.SolrException
2017-04-25 14:50:30,275 ERROR [catalina-exec-7] common.SolrException (SolrException.java:151):org.apache.catalina.connector.ClientAbortException: java.io.IOException: Broken pipe
原因:INSUITE®とLuxorの間のHTTPリクエストが切断されました。ミドルウェア処理がリクエストのやり取りに影響している可能性があります。
対処方法:INSUITE®とLuxorとの接続見直しが必要です。
[4-3] 出力例: impl.CloudSolrClient
2018-06-22 15:49:17,616 ERROR [http-nio-10082-exec-2] impl.CloudSolrClient (CloudSolrClient.java:1167) : Request to collection report failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry? 0 2018-06-22 15:49:17,617 ERROR [http-nio-10082-exec-2] impl.CloudSolrClient (CloudSolrClient.java:1167) : Request to collection report failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry? 1 2018-06-22 15:49:17,617 ERROR [http-nio-10082-exec-2] impl.CloudSolrClient (CloudSolrClient.java:1167) : Request to collection report failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry? 2 2018-06-22 15:49:17,618 ERROR [http-nio-10082-exec-2] impl.CloudSolrClient (CloudSolrClient.java:1167) : Request to collection report failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry? 3 2018-06-22 15:49:17,618 ERROR [http-nio-10082-exec-2] impl.CloudSolrClient (CloudSolrClient.java:1167) : Request to collection report failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry? 4 2018-06-22 15:49:17,619 ERROR [http-nio-10082-exec-2] impl.CloudSolrClient (CloudSolrClient.java:1167) : Request to collection report failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry? 5
原因:コレクションがすべて起動されていないうち、Solrに出力される可能性のある提示メッセージとなります。luxor.logにも類似ログが出力されます。
対処方法:特に影響のないログとなります。コレクションがすべて起動成功だと確認できたら、該当ログは出力されなくなります。
[4-4] 出力例: common.SolrException
2018-07-06 13:34:53,313 ERROR [OverseerThreadFactory-6-thread-5-processing-n:127.0.0.1:10080_solr] common.SolrException (SolrException.java:159) : Collection: process operation: create failed:org.apache.solr.common.SolrException: collection already exists: process at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:85) at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:226) at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748)
原因:コマンドsh setup.sh -createCollectionsの実行時に出力されます。既に存在しているコレクションを作り直そうと判断する場合の提示メッセージとなります。
対処方法:特に影響のないログとなります。
[5] /usr/local/luxor/tomcat/logs/catalina.outの出力例
[5-1] 出力例: history.SearchHistoryServlet
2019-04-24 19:24:26,633 ERROR [catalina-exec-3] history.SearchHistoryServlet (SearchHistoryServlet.java:130) : error occurred.component:[imp] function:[get] search_account:[1000777]
--
org.apache.solr.common.SolrException: Could not find a healthy node to handle the request.
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1377)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1134)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1237)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1237)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1237)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1237)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1237)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:1073)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:160)
at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:942)
at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:957)
at jp.co.dreamarts.luxor.search.history.SearchHistoryUtils.search(SearchHistoryUtils.java:456)
原因: Luxorサービスの起動処理中に、INSUITE/SmartDBからの操作で検索履歴とサジェスト機能を利用した場合に、下記のエラーメッセージが出力されます。
対処方法:特に影響のないログとなります。Luxorサービスが正常起動したら、本メッセージが出力されなくなります。
ローテート設定
Luxorに関連するログのローテート設定
Luxorに関連するログのローテートはlog4j.xmlにて指定します。デフォルトでは、日時によりログファイルの分割を行います。
設定例:
# cd /usr/local/solr/tomcat/webapps/solr/WEB-INF/classes/
# vi log4j.xml
<appender name="LUXOR_LOG" class="org.apache.log4j.**DailyRollingFileAppender**">
<param name="File" value="/var/log/luxor/luxor.log" />
<param name="DatePattern" value="'.'yyyyMMdd" />
<param name="Append" value="true" />
<param name="Encoding" value="UTF-8" />
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss,SSS} %-5p[%t] %C{2} (%F:%L) : %m%n" />
</layout>
</appender>
<appender name="SOLR_LOG" class="org.apache.log4j.**DailyRollingFileAppender**">
<param name="File" value="/var/log/luxor/solr.log" />
<param name="DatePattern" value="'.'yyyyMMdd" />
<param name="Append" value="true" />
<param name="Encoding" value="UTF-8" />
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss,SSS} %-5p[%t] %C{2} (%F:%L) : %m%n" />
</layout>
</appender>
日時によりログファイルの分割を行うDailyRollingFileAppenderクラスにおいて、ログ保存期間を日付単位で設定するパラメータlogMaxBackupDaysを設定します。保存期間を超えたLuxorのsolr.logとluxor.logの削除を行います。詳細は次の表に記載します。
表 Luxorのログ保存期間設定
- 設定ファイル:setup.conf
- ファイルパス:/root/luxor.2.1.0/setup.conf
※Ver.2.1.0の場合のパスを例にしています。各リビジョンに合わせ、読み替えてください。
要素名称 | 初期値 | 説明 |
---|---|---|
logMaxBackupDays | 0(単位:日) | 設定値より古い日付のログが削除される。設定値が0の場合、削除は行われない。 |
注意
1.ログローテート対象は、現時点でのlog4j.xmlのDatePatternにより生成されたログのみとします。DatePatternが変更された場合、変更前のDatePatternにより生成されたログファイルはローテート対象外となるため、ご注意ください。
2.logMaxBackupDaysの変更時、setup.confに設定反映とSolrTomcat再起動が必要です。
DailyRollingFileAppenderクラスのほか、ファイルサイズによりログファイルを分割するRollingFileAppenderクラスを指定することも可能です。
設定例:
# cd /usr/local/solr/tomcat/webapps/solr/WEB-INF/classes/
# vi log4j.xml
<appender name="SYSLOG" class="org.apache.log4j.**RollingFileAppender**">
<param name="File" value="/var/log/luxor/luxor.log" />
<param name="MaxFileSize" value="1MB" />
<param name="MaxBackupIndex" value="2" />
~~ 中略 ~~
</appender>
<appender name="SYSLOG\_SOLR" class="org.apache.log4j.**RollingFileAppender**">
<param name="File" value="/var/log/luxor/solr.log" />
<param name="MaxFileSize" value="10MB" />
<param name="MaxBackupIndex" value="20" />
~~ 中略 ~~
</appender>
# sudo service solrTomcat restart
Tomcatに関するログのローテート設定
Tomcatに関するログのローテート設定方法
Tomcatに関するファイルはlog4.xmlでのローテート設定は実施できませんが、OSのlogrotateを利用することでローテート設定が可能です。
以下は毎日0時0分に新たなcatalina.outファイルを作成する場合の設定例となります。
設定値の詳細な内容については、logrotateの仕様をご確認ください。
※ローテート対象ファイル: /usr/local/luxor/tomcat/logs/catalina.out
設定例:
# cd /etc/logrotate.d
# touch tomcat
# vi tomcat
下記のように設定してください。
---------------
/usr/local/luxor/tomcat/logs/catalina.out {
daily # 毎日ローテートする
rotate 5 # 5世代分古いログを残す
missingok # ログファイルがなくてもエラーを出さない
dateext # ローテーションしたファイルの末尾に日付をつける
compress # 圧縮する
notifempty # ログファイルが空ならローテーションしない
copytruncate # ログファイルをコピーし、内容を削除
}
設定完了後、下記のコマンドでローテート設定を有効にします。
# logrotate --force /etc/logrotate.d/tomcat
catalina.outが有効になっていることを確認します。
# ls -lh /usr/local/luxor/tomcat/logs/catalina.out*
-rw-r----- 1 webadmin webadmin 0 May 20 15:27 /usr/local/luxor/tomcat/logs/catalina.out
-rw-r----- 1 webadmin webadmin 2.7K Apr 28 10:37 /usr/local/luxor/tomcat/logs/catalina.out-20190520.gz
catalina.outが肥大化した場合の対応
Luxorの稼働中に肥大化したcatalina.outの中身をクリアしたい場合は、空文字列をcatalina.outにリダイレクトすることでクリアしてください。
中身をクリアする場合は、catalina.outをバックアップしてから実施することをお勧めです。
※ catalina.outを削除または移動してしまうと、次のtomcat起動のタイミングまで、ログ出力がされません。
# cd /usr/local/luxor/tomcat/logs/
# > catalina.out
localhost_access_log.YYYY-MM-DD.txtについて
localhost_access_log.YYYY-MM-DD.txtには、主にアクセスの時間、IPアドレス、アクセス先等の関連情報が出力されます。TomcatによるすべてのHTTPリクエストのアクセスログが出力されます。
本ログを出力する場合、ファイルサイズが膨大となります。(下記ログ例は実際の内容と異なる可能性があります。)
出力しない設定方法は、usr/local/solr/tomcat/conf/server.xmlの以下箇所をコメントアウトして、Luxorを再起動します。
<Valve className="org.apache.catalina.valves.AccessLogValve"
directory="logs" prefix="localhost_access_log." suffix=".txt" pattern="%h %l %u %t "%r" %s %b" />