You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@jackrabbit.apache.org by sbarriba <sb...@yahoo.co.uk> on 2008/06/24 09:47:16 UTC
Logging/Detecting slow JCR queries with Lucene
Hi all,
Our application makes quite heavy use of JCR queries. We're seeing some
scenarios where the IO utilisation is very high for a period of time. A
thread dump of Tomcat shows lots and lots of threads locked waiting on
<0x781fe1d0> (a org.apache.lucene.store.FSDirectory$FSIndexInput which is
locked by the thread below.
Given we have 140+ queries being used, is there a way to configure
JackRabbit and/or Lucene to log out slow queries equivalent to the
"log-slow-queries" provided by MySql?
Regards,
Shaun
Thread owning the lock
"TP-Processor6806" daemon prio=1 tid=0x6a94ff58 nid=0x2121 runnable
[0x67cf2000..0x67cf3da0]
at java.io.RandomAccessFile.readBytes(Native Method)
at java.io.RandomAccessFile.read(RandomAccessFile.java:315)
at
org.apache.lucene.store.FSDirectory$FSIndexInput.readInternal(FSDirectory.ja
va:550)
- locked <0x782053c8> (a
org.apache.lucene.store.FSDirectory$FSIndexInput$Descriptor)
at
org.apache.lucene.store.BufferedIndexInput.readBytes(BufferedIndexInput.java
:122)
at
org.apache.lucene.index.CompoundFileReader$CSIndexInput.readInternal(Compoun
dFileReader.java:240)
- locked <0x781fe1d0> (a
org.apache.lucene.store.FSDirectory$FSIndexInput)
at
org.apache.lucene.store.BufferedIndexInput.refill(BufferedIndexInput.java:14
3)
at
org.apache.lucene.store.BufferedIndexInput.readByte(BufferedIndexInput.java:
38)
at org.apache.lucene.store.IndexInput.readVInt(IndexInput.java:57)
at
org.apache.lucene.index.SegmentTermDocs.next(SegmentTermDocs.java:109)
at
org.apache.lucene.index.FilterIndexReader$FilterTermDocs.next(FilterIndexRea
der.java:47)
at
org.apache.jackrabbit.core.query.lucene.ReadOnlyIndexReader$FilteredTermDocs
..next(ReadOnlyIndexReader.java:281)
at org.apache.lucene.index.MultiTermDocs.next(MultiReader.java:375)
at
org.apache.jackrabbit.core.query.lucene.ChildAxisQuery$ChildAxisScorer.calcu
lateChildren(ChildAxisQuery.java:338)
at
org.apache.jackrabbit.core.query.lucene.ChildAxisQuery$ChildAxisScorer.next(
ChildAxisQuery.java:268)
at org.apache.lucene.search.Scorer.score(Scorer.java:48)
at
org.apache.jackrabbit.core.query.lucene.ChildAxisQuery$ChildAxisScorer.calcu
lateChildren(ChildAxisQuery.java:317)
at
org.apache.jackrabbit.core.query.lucene.ChildAxisQuery$ChildAxisScorer.next(
ChildAxisQuery.java:268)
at org.apache.lucene.search.Scorer.score(Scorer.java:48)
at
org.apache.jackrabbit.core.query.lucene.DescendantSelfAxisQuery$DescendantSe
lfAxisScorer.collectContextHits(DescendantSelfAxisQuery.java:305)
at
org.apache.jackrabbit.core.query.lucene.DescendantSelfAxisQuery$DescendantSe
lfAxisScorer.next(DescendantSelfAxisQuery.java:254)
at org.apache.lucene.search.Scorer.score(Scorer.java:48)
at org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:146)
at org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:124)
at org.apache.lucene.search.Hits.getMoreDocs(Hits.java:74)
at org.apache.lucene.search.Hits.<init>(Hits.java:61)
at org.apache.lucene.search.Searcher.search(Searcher.java:55)
at
org.apache.jackrabbit.core.query.lucene.SearchIndex.executeQuery(SearchIndex
..java:658)
at
org.apache.jackrabbit.core.query.lucene.QueryResultImpl.executeQuery(QueryRe
sultImpl.java:242)
at
org.apache.jackrabbit.core.query.lucene.QueryResultImpl.getResults(QueryResu
ltImpl.java:290)
at
org.apache.jackrabbit.core.query.lucene.QueryResultImpl.<init>(QueryResultIm
pl.java:192)
at
org.apache.jackrabbit.core.query.lucene.QueryImpl.execute(QueryImpl.java:138
)
at
org.apache.jackrabbit.core.query.QueryImpl.execute(QueryImpl.java:176)
RE: Logging/Detecting slow JCR queries with Lucene
Posted by sbarriba <sb...@yahoo.co.uk>.
Thanks Marcel. We'll look at enabling this logging.
Are there any tuning params we should be looking at to help with the
performance in this area in the short term?
Regards,
Shaun
-----Original Message-----
From: Marcel Reutegger [mailto:marcel.reutegger@gmx.net]
Sent: 24 June 2008 10:46
To: users@jackrabbit.apache.org
Subject: Re: Logging/Detecting slow JCR queries with Lucene
Hi,
sbarriba wrote:
> Hi all,
>
> Our application makes quite heavy use of JCR queries. We're seeing some
> scenarios where the IO utilisation is very high for a period of time. A
> thread dump of Tomcat shows lots and lots of threads locked waiting on
> <0x781fe1d0> (a org.apache.lucene.store.FSDirectory$FSIndexInput which is
> locked by the thread below.
not sure, but this might be related to:
https://issues.apache.org/jira/browse/JCR-1365
> Given we have 140+ queries being used, is there a way to configure
> JackRabbit and/or Lucene to log out slow queries equivalent to the
> "log-slow-queries" provided by MySql?
when you enable debug log messages for
org.apache.jackrabbit.core.query.QueryImpl you will see timing information
as
well as the query statement, though you'll have to post process that
information
because *all* queries will be logged, not just slow ones.
regards
marcel
Re: Logging/Detecting slow JCR queries with Lucene
Posted by Marcel Reutegger <ma...@gmx.net>.
Hi,
sbarriba wrote:
> Hi all,
>
> Our application makes quite heavy use of JCR queries. We're seeing some
> scenarios where the IO utilisation is very high for a period of time. A
> thread dump of Tomcat shows lots and lots of threads locked waiting on
> <0x781fe1d0> (a org.apache.lucene.store.FSDirectory$FSIndexInput which is
> locked by the thread below.
not sure, but this might be related to:
https://issues.apache.org/jira/browse/JCR-1365
> Given we have 140+ queries being used, is there a way to configure
> JackRabbit and/or Lucene to log out slow queries equivalent to the
> "log-slow-queries" provided by MySql?
when you enable debug log messages for
org.apache.jackrabbit.core.query.QueryImpl you will see timing information as
well as the query statement, though you'll have to post process that information
because *all* queries will be logged, not just slow ones.
regards
marcel