lucene-general mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Uwe Schindler" <...@thetaphi.de>
Subject RE: Experiencing High CPU load with 3.3
Date Sat, 23 Jul 2011 10:29:26 GMT
Hi Alan,

We don't see such problems here on our machines, so first we need to know
some things:

Do you open a new index reader before each search and close it afterwards?
In normal Lucene usage you keep the IndexReaders open all the time and only
reopen them when your underlying index changed. If you keep the IndexReader
open, such close() calls with doPrivileged will not happen so often.

The problem in Lucene 3.3 is that the default on 64 bit Linux is to use
memory mapping, which is implemented by the operating system like a swap
file mapped into virtual address space. This makes searches very fast, as
the whole index is somehow in cache RAM and can be accessed like memory
swapped out into a swap file. This memory mapping is much more expensive
than simple opening a file and closing it after usage. If you reopen the
indexreader all the time, this expensive mapping cost is what you see all
the time.

So I would suggest you check:
a) Only open/close IndexReaders when you really need it. You can use one
IndexReader and even handle multiple parallel searches on it (it's thread
safe).
b) If you need to reopen quite often, don't use the defaults
FSDirectory.open(), but instead choose a Directory implementation yourself.
To get the behavior of Lucene 3.2, use new NIOFSDirectory(...). But on Linux
64, searches will be slower than with MMap (if you keep readers open).
c) Is your JVM somehow closed down in terms of security? These doPrivileged
mappings are only effective, when you have a web application container that
restricts web applications to run with low privileges (something like
Windows Vista/7 UAC). In this case, doPrivileged may be expensive and is not
simply a noop. For Lucene/Solr it's always recommened not to run it in
restricted Java environments. Maybe OpenBD does this - I have no idea.

Uwe

-----
Uwe Schindler
H.-H.-Meier-Allee 63, D-28213 Bremen
http://www.thetaphi.de
eMail: uwe@thetaphi.de


> -----Original Message-----
> From: Alan Williamson (aw2.0 cloud experts) [mailto:alan@aw20.co.uk]
> Sent: Saturday, July 23, 2011 9:42 AM
> To: general@lucene.apache.org
> Subject: Experiencing High CPU load with 3.3
> 
> Good day all.
> 
> We area a long term user of Lucene with it powering our search engine
inside
> of the Java CFML runtime OpenBD (http://openbd.org).  We've had no
> complaints from it whatsoever.  Until now that is.
> 
> Since moving to 3.3 we have been experiencing extremely high CPU load
> when searching against an index.  The index is only 19MB in size with all
of
> 40,000 items in it.
> 
> We have produced some very useful stack traces with CPU % load times.
> Some other data points.  This is not happening to just one machine, this
is
> happening to all the machines in the web farm.  The actual traffic on the
> machine is low, the stack traces i give you, the only threads that are
actually
> doing anything, are the ones were Lucene has gone into a tizzy.  The
> machines have all 3.5GB of memory.  Running Java 1.6.23
> 
> Thanks
> 
> alan
> 
> ------- Sample #1 -----------------------------------------
> 
> "qtp274064735-1462" prio=10 tid=0x00002aaacaa62800 nid=19115 runnable
> [0x000000004174d000]
>     java.lang.Thread.State: RUNNABLE
> 	at java.security.AccessController.doPrivileged(Native Method)
> 	at
> org.apache.lucene.store.MMapDirectory.cleanMapping(MMapDirectory.jav
> a:158)
> 	at
> org.apache.lucene.store.MMapDirectory$MMapIndexInput.close(MMapDir
> ectory.java:383)
> 	at
> org.apache.lucene.index.CompoundFileReader.close(CompoundFileReader.j
> ava:137)
> 	- locked<0x0000000795b86520>  (a
> org.apache.lucene.index.CompoundFileReader)
> 	at
> org.apache.lucene.index.SegmentInfos.read(SegmentInfos.java:302)
> 	at
> org.apache.lucene.index.SegmentInfos$1.doBody(SegmentInfos.java:359)
> 	at
> org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfo
> s.java:750)
> 	at
> org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfo
> s.java:589)
> 	at
> org.apache.lucene.index.SegmentInfos.read(SegmentInfos.java:355)
> 	at
> org.apache.lucene.index.SegmentInfos.readCurrentVersion(SegmentInfos.j
> ava:476)
> 	at
>
org.apache.lucene.index.DirectoryReader.initialize(DirectoryReader.java:347
> )
> 	at
> org.apache.lucene.index.DirectoryReader.<init>(DirectoryReader.java:130)
> 	at
> org.apache.lucene.index.DirectoryReader$1.doBody(DirectoryReader.java:8
> 3)
> 	at
> org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfo
> s.java:750)
> 	at
> org.apache.lucene.index.DirectoryReader.open(DirectoryReader.java:75)
> 	at
> org.apache.lucene.index.IndexReader.open(IndexReader.java:428)
> 	at
> org.apache.lucene.index.IndexReader.open(IndexReader.java:288)
> 
> "qtp274064735-764" prio=10 tid=0x00002aaabb15f000 nid=16453 runnable
> [0x0000000041bd6000]
>     java.lang.Thread.State: RUNNABLE
> 	at java.io.UnixFileSystem.list(Native Method)
> 	at java.io.File.list(File.java:973)
> 	at java.io.File.list(File.java:1004)
> 	at org.apache.lucene.store.FSDirectory.listAll(FSDirectory.java:223)
> 	at org.apache.lucene.store.FSDirectory.listAll(FSDirectory.java:241)
> 	at
> org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfo
> s.java:637)
> 	at
> org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfo
> s.java:589)
> 	at
> org.apache.lucene.index.SegmentInfos.read(SegmentInfos.java:355)
> 	at
> org.apache.lucene.index.SegmentInfos.readCurrentVersion(SegmentInfos.j
> ava:476)
> 	at
>
org.apache.lucene.index.DirectoryReader.initialize(DirectoryReader.java:347
> )
> 	at
> org.apache.lucene.index.DirectoryReader.<init>(DirectoryReader.java:130)
> 	at
> org.apache.lucene.index.DirectoryReader$1.doBody(DirectoryReader.java:8
> 3)
> 	at
> org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfo
> s.java:750)
> 	at
> org.apache.lucene.index.DirectoryReader.open(DirectoryReader.java:75)
> 	at
> org.apache.lucene.index.IndexReader.open(IndexReader.java:428)
> 	at
> org.apache.lucene.index.IndexReader.open(IndexReader.java:288)
> 
>    PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
> 16453 nobody    18   0 8149m 3.6g  80m R 57.4 47.3   4:45.53 java
> 19115 nobody    18   0 8149m 3.6g  80m R 50.2 47.3   2:01.15 java
> 
> ------- Sample #2 -----------------------------------------
> 
> "qtp2001061977-4696" prio=10 tid=0x00002aaac0816800 nid=4710 runnable
> [0x0000000041950000]
>     java.lang.Thread.State: RUNNABLE
> 	at
> org.apache.lucene.index.TermInfosReader.<init>(TermInfosReader.java:121
> )
> 	at
> org.apache.lucene.index.SegmentCoreReaders.<init>(SegmentCoreReaders
> .java:75)
> 	at
> org.apache.lucene.index.SegmentReader.get(SegmentReader.java:114)
> 	at
> org.apache.lucene.index.SegmentReader.get(SegmentReader.java:92)
> 	at
> org.apache.lucene.index.DirectoryReader.<init>(DirectoryReader.java:113)
> 	at
> org.apache.lucene.index.DirectoryReader$1.doBody(DirectoryReader.java:8
> 3)
> 	at
> org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfo
> s.java:750)
> 	at
> org.apache.lucene.index.DirectoryReader.open(DirectoryReader.java:75)
> 	at
> org.apache.lucene.index.IndexReader.open(IndexReader.java:428)
> 	at
> org.apache.lucene.index.IndexReader.open(IndexReader.java:288)
> 
> "qtp2001061977-15" prio=10 tid=0x00002aaab8e07000 nid=28622 runnable
> [0x0000000040c37000]
>     java.lang.Thread.State: RUNNABLE
> 	at java.security.AccessController.doPrivileged(Native Method)
> 	at
> org.apache.lucene.store.MMapDirectory.cleanMapping(MMapDirectory.jav
> a:158)
> 	at
> org.apache.lucene.store.MMapDirectory$MMapIndexInput.close(MMapDir
> ectory.java:383)
> 	at
> org.apache.lucene.index.CompoundFileReader.close(CompoundFileReader.j
> ava:137)
> 	- locked<0x000000076e7bf9c0>  (a
> org.apache.lucene.index.CompoundFileReader)
> 	at
> org.apache.lucene.index.SegmentCoreReaders.decRef(SegmentCoreReader
> s.java:191)
> 	- locked<0x000000076e7bf960>  (a
> org.apache.lucene.index.SegmentCoreReaders)
> 	at
> org.apache.lucene.index.SegmentReader.doClose(SegmentReader.java:387)
> 	at
> org.apache.lucene.index.IndexReader.decRef(IndexReader.java:242)
> 	at
> org.apache.lucene.index.DirectoryReader.doClose(DirectoryReader.java:895
> )
> 	- locked<0x000000076e7bef98>  (a
> org.apache.lucene.index.DirectoryReader)
> 	at
> org.apache.lucene.index.IndexReader.decRef(IndexReader.java:242)
> 	at
> org.apache.lucene.index.IndexReader.close(IndexReader.java:1209)
> 	- locked<0x000000076e7bef98>  (a
> org.apache.lucene.index.DirectoryReader)
> 
>   4710 nobody    18   0 8172m 3.2g  82m R 79.1 42.6   4:22.84 java
> 28622 nobody    18   0 8172m 3.2g  82m D 69.2 42.6  12:39.49 java
> 
> ------- Sample #3 -----------------------------------------
> 
> 
> "qtp683347213-3129" prio=10 tid=0x00002aaac07fd000 nid=29916 runnable
> [0x0000000042b73000]
>     java.lang.Thread.State: RUNNABLE
> 	at
> org.apache.lucene.index.IndexFileNames.fileNameFromGeneration(IndexFil
> eNames.java:189)
> 	at
> org.apache.lucene.index.SegmentInfo.getNormFileName(SegmentInfo.java:
> 508)
> 	at
> org.apache.lucene.index.SegmentReader.openNorms(SegmentReader.java:
> 639)
> 	at
> org.apache.lucene.index.SegmentReader.get(SegmentReader.java:119)
> 	at
> org.apache.lucene.index.SegmentReader.get(SegmentReader.java:92)
> 	at
> org.apache.lucene.index.DirectoryReader.<init>(DirectoryReader.java:113)
> 	at
> org.apache.lucene.index.DirectoryReader$1.doBody(DirectoryReader.java:8
> 3)
> 	at
> org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfo
> s.java:750)
> 	at
> org.apache.lucene.index.DirectoryReader.open(DirectoryReader.java:75)
> 	at
> org.apache.lucene.index.IndexReader.open(IndexReader.java:428)
> 
> 29916 nobody    22   0 7922m 4.3g  92m R 73.1 57.7   5:53.96 java



Mime
View raw message