You are viewing a plain text version of this content. The canonical link for it is here.
Posted to oak-issues@jackrabbit.apache.org by "Chetan Mehrotra (JIRA)" <ji...@apache.org> on 2016/11/20 16:38:58 UTC
[jira] [Commented] (OAK-4836) Avoid excessive logging in case of
corrupt index or mis-configured index defnition
[ https://issues.apache.org/jira/browse/OAK-4836?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15681422#comment-15681422 ]
Chetan Mehrotra commented on OAK-4836:
--------------------------------------
Introduced a {{BadIndexTracker}} (r1770371) which would keep track of bad indexes. Upon detecting a bad index it would log a error log for the first time
{noformat}
2016-11-18 14:45:19,348 ERROR NA [FelixStartLevel] o.a.j.o.p.i.l.BadIndexTracker - Could not access the Lucene index at [/oak:index/lucene]
java.lang.AssertionError: numBytes=-13
at org.apache.lucene.store.DataOutput.copyBytes(DataOutput.java:244)
at org.apache.lucene.store.Directory.copy(Directory.java:186)
at org.apache.jackrabbit.oak.plugins.index.lucene.directory.CopyOnReadDirectory.copyFilesToLocal(CopyOnReadDirectory.java:199)
{noformat}
Then for further access it would log at DEBUG level and the index would not be accessed
{noformat}
2016-11-18 14:45:29,543 DEBUG admin [127.0.0.1 [1479460529454] GET /libs/crx/core/content/welcome.html HTTP/1.1] o.a.j.o.p.i.l.BadIndexTracker - Ignoring index [/oak:index/lucene] which is not working correctly since 10.20 s ,0 indexing cycles, accessed 1 times
{noformat}
Then after 15 min if the index is accessed then it would check again and in case of failure would log an ERROR message. (Log below is for 1 min check in test scenario)
{noformat}
2016-11-18 14:46:24,271 ERROR NA [qtp251997596-163] o.a.j.o.p.i.l.BadIndexTracker - Could not access the Lucene index at [/oak:index/lucene] . since 1.082 min ,0 indexing cycles, accessed 7 times
java.lang.AssertionError: numBytes=-13
at org.apache.lucene.store.DataOutput.copyBytes(DataOutput.java:244)
at org.apache.lucene.store.Directory.copy(Directory.java:186)
at org.apache.jackrabbit.oak.plugins.index.lucene.directory.CopyOnReadDirectory.copyFilesToLocal(CopyOnReadDirectory.java:199)
at org.apache.jackrabbit.oak.plugins.index.lucene.directory.CopyOnReadDirectory.prefetchIndexFiles(CopyOnReadDirectory.java:170)
{noformat}
Later post reindexing when index starts working again then it would be detected and an INFO level message would be logged and index would be used
{noformat}
2016-11-18 14:47:04,532 INFO NA [oak-lucene-1] o.a.j.o.p.i.l.BadIndexTracker - Index [/oak:index/lucene] which was not working since 1.753 min ,1 indexing cycles, accessed 8 times is found to be healthy again
{noformat}
> Avoid excessive logging in case of corrupt index or mis-configured index defnition
> ----------------------------------------------------------------------------------
>
> Key: OAK-4836
> URL: https://issues.apache.org/jira/browse/OAK-4836
> Project: Jackrabbit Oak
> Issue Type: Improvement
> Components: lucene
> Reporter: Vikas Saurabh
> Assignee: Chetan Mehrotra
> Fix For: 1.6
>
>
> Following up from comment\[0] from [~chetanm] in OAK-4805, in case of corrupt index or mis-configured index defnition the logs tend to fill up with same exception over and over. It would be useful for index tracker to keep track of such index and ignore those for any processing until some change is detected on the definition (reindex would also lead to a change on index).
> We might also want to expose a jmx which lists the indices that tracker thinks are bad (and probably also why it started to think that).
> \[0]: https://issues.apache.org/jira/browse/OAK-4805?focusedCommentId=15492487&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-15492487
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)