lucene-java-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Piotr Idzikowski <piotridzikow...@gmail.com>
Subject Lucene search/count performance abrupt degradation (MMapDirectory)
Date Tue, 23 Dec 2014 20:32:34 GMT
Hello.

I have a performance problem with Lucene search queries running on Java
7u71 Linux platform. I use the newest 4.10 version, but we also experience
the same problem with Lucene 4.7.2.

I observed that after some time (1 or 2 days), even without any heavy use,
Lucene search and count slow down abruptly, from 1-2 seconds to 30-40,
without any intermediate steps and regardless of type of filters/terms used
(or not). No index writing downgrade has been observed.

Analysing jstack results I can see some threads get stuck in exactly the
same place, depending on the Lucene version, most probably due to certain
rearrangements in the index structure for the 4.10 version
(NumericDocValuesField for select fields):


--- In Lucene 4.10:

Thread 4043: (state = IN_JAVA)

 - java.nio.DirectByteBuffer.getInt(int) @bci=5, line=675 (Interpreted
frame)
 -
org.apache.lucene.store.ByteBufferIndexInput$SingleBufferImpl.readInt(long)
@bci=6, line=480 (Interpreted frame)
 -
org.apache.lucene.util.packed.DirectReader$DirectPackedReader28.get(long)
@bci=23, line=222 (Interpreted frame)
 -
org.apache.lucene.codecs.lucene410.Lucene410DocValuesProducer$2.get(long)
@bci=13, line=369 (Interpreted frame)
 - org.apache.lucene.util.LongValues.get(int) @bci=3, line=45 (Interpreted
frame)
 - org.apache.lucene.search.FieldCacheImpl$7.get(int) @bci=5, line=929
(Compiled frame)
 - org.apache.lucene.search.FieldCacheRangeFilter$6$1.matchDoc(int) @bci=5,
line=397 (Compiled frame)
 - org.apache.lucene.search.FieldCacheDocIdSet$3.nextDoc() @bci=40, line=92
(Compiled frame)
 -
org.apache.lucene.util.FixedBitSet.or(org.apache.lucene.search.DocIdSetIterator)
@bci=89, line=342 (Compiled frame)
 -
org.apache.lucene.queries.ChainedFilter.initialResult(org.apache.lucene.index.AtomicReaderContext,
int, int[]) @bci=40, line=134 (Compiled frame)
 -
org.apache.lucene.queries.ChainedFilter.getDocIdSet(org.apache.lucene.index.AtomicReaderContext,
int, int[]) @bci=4, line=153 (Compiled frame)
 -
org.apache.lucene.queries.ChainedFilter.getDocIdSet(org.apache.lucene.index.AtomicReaderContext,
org.apache.lucene.util.Bits) @bci=23, line=105 (Interpreted frame)
 -
org.apache.lucene.search.FilteredQuery$1.bulkScorer(org.apache.lucene.index.AtomicReaderContext,
boolean, org.apache.lucene.util.Bits) @bci=33, line=144 (Compiled frame)
 - org.apache.lucene.search.IndexSearcher.search(java.util.List,
org.apache.lucene.search.Weight, org.apache.lucene.search.Collector)
@bci=67, line=618 (Compiled frame)



--- In Lucene 4.7:

Thread 9481: (state = IN_JAVA)

 - org.apache.lucene.search.FieldCacheImpl$LongsFromArray.get(int) @bci=9,
line=915 (Compiled frame; information may be imprecise)
 - org.apache.lucene.search.FieldCacheRangeFilter$6$1.matchDoc(int) @bci=5,
line=397 (Compiled frame)
 - org.apache.lucene.search.FieldCacheDocIdSet$3.nextDoc() @bci=40,
line=101 (Compiled frame)
 -
org.apache.lucene.util.FixedBitSet.or(org.apache.lucene.search.DocIdSetIterator)
@bci=89, line=343 (Compiled frame)
 -
org.apache.lucene.queries.ChainedFilter.initialResult(org.apache.lucene.index.AtomicReaderContext,
int, int[]) @bci=40, line=134 (Compiled frame)
 -
org.apache.lucene.queries.ChainedFilter.getDocIdSet(org.apache.lucene.index.AtomicReaderContext,
int, int[]) @bci=4, line=153 (Compiled frame)
 -
org.apache.lucene.queries.ChainedFilter.getDocIdSet(org.apache.lucene.index.AtomicReaderContext,
org.apache.lucene.util.Bits) @bci=23, line=105 (Compiled frame)
 -
org.apache.lucene.search.FilteredQuery$1.scorer(org.apache.lucene.index.AtomicReaderContext,
boolean, boolean, org.apache.lucene.util.Bits) @bci=34, line=130 (Compiled
frame)
 - org.apache.lucene.search.IndexSearcher.search(java.util.List,
org.apache.lucene.search.Weight, org.apache.lucene.search.Collector)
@bci=68, line=618 (Compiled frame)
 -
org.apache.lucene.search.IndexSearcher.search(org.apache.lucene.search.Query,
org.apache.lucene.search.Filter, org.apache.lucene.search.Collector)
@bci=16, line=297 (Interpreted frame)



The most puzzling thing is that this immediate degradation happens only on
the biggest machines, with the highest number of processors and RAM
available (and assigned). Interestingly smaller machines (in number of
cores and RAM), with indexes of bigger or smaller size do not display any
degradation.

The whole application is run on Glassfish 3.1.2 server and any attempt to
close MMapDirectory and readers (through SearcherManager), or simply
undeploy/deploy the application, or stopping index writer process does not
change the declined performance state. Only the full Glassfish/JVM restart
brings back the original speed, alas for a day or two only.

Here is some additional information of the affected set-up with Lucene 4.10
(vs some issue-free instances):


1. Index folder size: 18G (vs 6G or 21G on issue-free servers)


2. JVM's Xmx & Xms set to 26G (vs 16G or 7G! on issue-free server)

NOTE: the actual consumption of Java heap never surpasses 10G anywhere


3. Hardware:

    DELL PowerEdge R820, 256G RAM, 32 CPUs Intel Xeon E5-4640 2.4GHz
300GB SFF 15K RPM (6 Gb/s) Drive, HDD RPM: 15000.  RAID 1 hardware,
ext3/ext4 filesystem on LVM

vs issue-free

    DELL PowerEdge R720, 128G RAM, 16 CPUs Intel Xeon E5-2680 2.7GHz
300GB SFF 15K RPM (6 Gb/s) Drive, HDD RPM: 15000.  RAID 1 hardware, ext3
filesystem on LVM


4. OS:

  Red Hat Enterprise Linux Server release 6.6 (Santiago) # This is a "SLES
Expanded Support platform release 6.6"

  Red Hat Enterprise Linux Server release 5.11 (Tikanga)


NOTES:

 - both peformance issue and issue-free behaviour has been observed on
either of these platforms
 - each instance has a mySQL database (InnoDB engine) running with no
performance issues detected


5. vm.max_map_count = 65530
   vm.swappiness = 0


6. ulimit -m = unlimited
   ulimit -l = 64
   ulimit -v = unlimited
   ulimit -n = 65535


Index folder details with the performance issue instance (reindexed 22th
Dec 2014):

-rw-r--r-- 1 glassfish glassfish       8603 Dec 23 13:43 _3nr_27.del
-rw-r--r-- 1 glassfish glassfish  500359541 Dec 22 16:11 _3nr.fdt
-rw-r--r-- 1 glassfish glassfish     315153 Dec 22 16:11 _3nr.fdx
-rw-r--r-- 1 glassfish glassfish       2342 Dec 22 16:14 _3nr.fnm
-rw-r--r-- 1 glassfish glassfish  175275056 Dec 22 16:14
_3nr_Lucene410_0.dvd
-rw-r--r-- 1 glassfish glassfish        181 Dec 22 16:14
_3nr_Lucene410_0.dvm
-rw-r--r-- 1 glassfish glassfish 2188210769 Dec 22 16:14 _3nr_Lucene41_0.doc
-rw-r--r-- 1 glassfish glassfish 1548092715 Dec 22 16:14 _3nr_Lucene41_0.pos
-rw-r--r-- 1 glassfish glassfish  751436802 Dec 22 16:14 _3nr_Lucene41_0.tim
-rw-r--r-- 1 glassfish glassfish   13999667 Dec 22 16:14 _3nr_Lucene41_0.tip
-rw-r--r-- 1 glassfish glassfish  101475702 Dec 22 16:14 _3nr.nvd
-rw-r--r-- 1 glassfish glassfish        141 Dec 22 16:14 _3nr.nvm
-rw-r--r-- 1 glassfish glassfish        449 Dec 22 16:14 _3nr.si
-rw-r--r-- 1 glassfish glassfish       2644 Dec 23 13:43 _421_1x.del
-rw-r--r-- 1 glassfish glassfish  121455459 Dec 22 16:33 _421.fdt
-rw-r--r-- 1 glassfish glassfish      71727 Dec 22 16:33 _421.fdx
-rw-r--r-- 1 glassfish glassfish       2342 Dec 22 16:34 _421.fnm
-rw-r--r-- 1 glassfish glassfish   36762556 Dec 22 16:34
_421_Lucene410_0.dvd
-rw-r--r-- 1 glassfish glassfish        181 Dec 22 16:34
_421_Lucene410_0.dvm
-rw-r--r-- 1 glassfish glassfish  389067295 Dec 22 16:34 _421_Lucene41_0.doc
-rw-r--r-- 1 glassfish glassfish  217957881 Dec 22 16:34 _421_Lucene41_0.pos
-rw-r--r-- 1 glassfish glassfish  206031060 Dec 22 16:34 _421_Lucene41_0.tim
-rw-r--r-- 1 glassfish glassfish    4223546 Dec 22 16:34 _421_Lucene41_0.tip
-rw-r--r-- 1 glassfish glassfish   21625858 Dec 22 16:34 _421.nvd
-rw-r--r-- 1 glassfish glassfish        141 Dec 22 16:34 _421.nvm
-rw-r--r-- 1 glassfish glassfish        450 Dec 22 16:34 _421.si
-rw-r--r-- 1 glassfish glassfish      14947 Dec 23 13:43 _7wu_3u.del
-rw-r--r-- 1 glassfish glassfish  597109930 Dec 22 20:19 _7wu.fdt
-rw-r--r-- 1 glassfish glassfish     355197 Dec 22 20:19 _7wu.fdx
-rw-r--r-- 1 glassfish glassfish       2342 Dec 22 20:23 _7wu.fnm
-rw-r--r-- 1 glassfish glassfish  194040056 Dec 22 20:23
_7wu_Lucene410_0.dvd
-rw-r--r-- 1 glassfish glassfish        181 Dec 22 20:23
_7wu_Lucene410_0.dvm
-rw-r--r-- 1 glassfish glassfish 2211307090 Dec 22 20:23 _7wu_Lucene41_0.doc
-rw-r--r-- 1 glassfish glassfish 1212527515 Dec 22 20:23 _7wu_Lucene41_0.pos
-rw-r--r-- 1 glassfish glassfish  826659180 Dec 22 20:23 _7wu_Lucene41_0.tim
-rw-r--r-- 1 glassfish glassfish   16374356 Dec 22 20:23 _7wu_Lucene41_0.tip
-rw-r--r-- 1 glassfish glassfish  118580702 Dec 22 20:23 _7wu.nvd
-rw-r--r-- 1 glassfish glassfish        141 Dec 22 20:23 _7wu.nvm
-rw-r--r-- 1 glassfish glassfish        450 Dec 22 20:23 _7wu.si
-rw-r--r-- 1 glassfish glassfish        388 Dec 23 13:31 _ajv_1b.del
-rw-r--r-- 1 glassfish glassfish        350 Dec 22 22:53 _ajv.cfe
-rw-r--r-- 1 glassfish glassfish  199163569 Dec 22 22:53 _ajv.cfs
-rw-r--r-- 1 glassfish glassfish        301 Dec 22 22:53 _ajv.si
-rw-r--r-- 1 glassfish glassfish      10653 Dec 23 13:41 _amn_4j.del
-rw-r--r-- 1 glassfish glassfish  450510940 Dec 22 22:58 _amn.fdt
-rw-r--r-- 1 glassfish glassfish     272063 Dec 22 22:58 _amn.fdx
-rw-r--r-- 1 glassfish glassfish       2342 Dec 22 23:02 _amn.fnm
-rw-r--r-- 1 glassfish glassfish  147330056 Dec 22 23:02
_amn_Lucene410_0.dvd
-rw-r--r-- 1 glassfish glassfish        181 Dec 22 23:02
_amn_Lucene410_0.dvm
-rw-r--r-- 1 glassfish glassfish 2248610483 Dec 22 23:02 _amn_Lucene41_0.doc
-rw-r--r-- 1 glassfish glassfish 1609057525 Dec 22 23:02 _amn_Lucene41_0.pos
-rw-r--r-- 1 glassfish glassfish  713702544 Dec 22 23:02 _amn_Lucene41_0.tim
-rw-r--r-- 1 glassfish glassfish   14108217 Dec 22 23:02 _amn_Lucene41_0.tip
-rw-r--r-- 1 glassfish glassfish   90035702 Dec 22 23:02 _amn.nvd
-rw-r--r-- 1 glassfish glassfish        141 Dec 22 23:02 _amn.nvm
-rw-r--r-- 1 glassfish glassfish        449 Dec 22 23:02 _amn.si
-rw-r--r-- 1 glassfish glassfish        482 Dec 23 13:23 _aot_1v.del
-rw-r--r-- 1 glassfish glassfish        350 Dec 22 23:02 _aot.cfe
-rw-r--r-- 1 glassfish glassfish  192102720 Dec 22 23:02 _aot.cfs
-rw-r--r-- 1 glassfish glassfish        301 Dec 22 23:02 _aot.si
-rw-r--r-- 1 glassfish glassfish        421 Dec 23 13:31 _aq2_1q.del
-rw-r--r-- 1 glassfish glassfish        350 Dec 22 23:03 _aq2.cfe
-rw-r--r-- 1 glassfish glassfish  255543219 Dec 22 23:03 _aq2.cfs
-rw-r--r-- 1 glassfish glassfish        301 Dec 22 23:03 _aq2.si
-rw-r--r-- 1 glassfish glassfish       6296 Dec 23 13:09 _arg_1n.del
-rw-r--r-- 1 glassfish glassfish        350 Dec 22 23:06 _arg.cfe
-rw-r--r-- 1 glassfish glassfish   22582413 Dec 22 23:06 _arg.cfs
-rw-r--r-- 1 glassfish glassfish        301 Dec 22 23:06 _arg.si
-rw-r--r-- 1 glassfish glassfish        350 Dec 22 23:32 _as0.cfe
-rw-r--r-- 1 glassfish glassfish    4887961 Dec 22 23:32 _as0.cfs
-rw-r--r-- 1 glassfish glassfish       1268 Dec 23 04:08 _as0_p.del
-rw-r--r-- 1 glassfish glassfish        301 Dec 22 23:32 _as0.si
-rw-r--r-- 1 glassfish glassfish        350 Dec 22 23:37 _asb.cfe
-rw-r--r-- 1 glassfish glassfish    8007352 Dec 22 23:37 _asb.cfs
-rw-r--r-- 1 glassfish glassfish       1596 Dec 23 13:01 _asb_o.del
-rw-r--r-- 1 glassfish glassfish        301 Dec 22 23:37 _asb.si
-rw-r--r-- 1 glassfish glassfish        968 Dec 23 11:31 _atg_19.del
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 00:07 _atg.cfe
-rw-r--r-- 1 glassfish glassfish    4066236 Dec 23 00:07 _atg.cfs
-rw-r--r-- 1 glassfish glassfish        301 Dec 23 00:07 _atg.si
-rw-r--r-- 1 glassfish glassfish        760 Dec 23 13:27 _atq_2f.del
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 00:13 _atq.cfe
-rw-r--r-- 1 glassfish glassfish  170864354 Dec 23 00:13 _atq.cfs
-rw-r--r-- 1 glassfish glassfish        301 Dec 23 00:13 _atq.si
-rw-r--r-- 1 glassfish glassfish       1628 Dec 23 11:31 _b61_13.del
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 03:47 _b61.cfe
-rw-r--r-- 1 glassfish glassfish    5999917 Dec 23 03:47 _b61.cfs
-rw-r--r-- 1 glassfish glassfish        301 Dec 23 03:47 _b61.si
-rw-r--r-- 1 glassfish glassfish       2426 Dec 23 11:31 _b9p_12.del
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 04:50 _b9p.cfe
-rw-r--r-- 1 glassfish glassfish   10325273 Dec 23 04:50 _b9p.cfs
-rw-r--r-- 1 glassfish glassfish        301 Dec 23 04:50 _b9p.si
-rw-r--r-- 1 glassfish glassfish       7252 Dec 23 13:14 _bg3_1i.del
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 06:52 _bg3.cfe
-rw-r--r-- 1 glassfish glassfish   27333130 Dec 23 06:52 _bg3.cfs
-rw-r--r-- 1 glassfish glassfish        301 Dec 23 06:52 _bg3.si
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 08:06 _bkb.cfe
-rw-r--r-- 1 glassfish glassfish    3124229 Dec 23 08:06 _bkb.cfs
-rw-r--r-- 1 glassfish glassfish        301 Dec 23 08:06 _bkb.si
-rw-r--r-- 1 glassfish glassfish        917 Dec 23 13:02 _bkb_z.del
-rw-r--r-- 1 glassfish glassfish       1074 Dec 23 13:41 _bol_12.del
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 09:55 _bol.cfe
-rw-r--r-- 1 glassfish glassfish    4043642 Dec 23 09:55 _bol.cfs
-rw-r--r-- 1 glassfish glassfish        301 Dec 23 09:55 _bol.si
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 10:54 _bry.cfe
-rw-r--r-- 1 glassfish glassfish    5790021 Dec 23 10:54 _bry.cfs
-rw-r--r-- 1 glassfish glassfish       1691 Dec 23 13:20 _bry_m.del
-rw-r--r-- 1 glassfish glassfish        301 Dec 23 10:54 _bry.si
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 11:33 _bu6.cfe
-rw-r--r-- 1 glassfish glassfish    5700578 Dec 23 11:33 _bu6.cfs
-rw-r--r-- 1 glassfish glassfish       1855 Dec 23 13:42 _bu6_n.del
-rw-r--r-- 1 glassfish glassfish        301 Dec 23 11:33 _bu6.si
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 12:34 _bwy.cfe
-rw-r--r-- 1 glassfish glassfish    3720555 Dec 23 12:34 _bwy.cfs
-rw-r--r-- 1 glassfish glassfish        720 Dec 23 13:43 _bwy_l.del
-rw-r--r-- 1 glassfish glassfish        301 Dec 23 12:34 _bwy.si
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 13:03 _byn.cfe
-rw-r--r-- 1 glassfish glassfish    5097683 Dec 23 13:03 _byn.cfs
-rw-r--r-- 1 glassfish glassfish       1137 Dec 23 13:43 _byn_f.del
-rw-r--r-- 1 glassfish glassfish        301 Dec 23 13:03 _byn.si
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 13:09 _byx.cfe
-rw-r--r-- 1 glassfish glassfish    7921902 Dec 23 13:09 _byx.cfs
-rw-r--r-- 1 glassfish glassfish       1804 Dec 23 13:35 _byx_d.del
-rw-r--r-- 1 glassfish glassfish        301 Dec 23 13:09 _byx.si
-rw-r--r-- 1 glassfish glassfish        667 Dec 23 13:41 _c0b_5.del
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 13:34 _c0b.cfe
-rw-r--r-- 1 glassfish glassfish    2099223 Dec 23 13:34 _c0b.cfs
-rw-r--r-- 1 glassfish glassfish        301 Dec 23 13:34 _c0b.si
-rw-r--r-- 1 glassfish glassfish        343 Dec 23 13:43 _c0l_3.del
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 13:40 _c0l.cfe
-rw-r--r-- 1 glassfish glassfish    1936118 Dec 23 13:40 _c0l.cfs
-rw-r--r-- 1 glassfish glassfish        301 Dec 23 13:40 _c0l.si
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 13:41 _c0m.cfe
-rw-r--r-- 1 glassfish glassfish      20135 Dec 23 13:41 _c0m.cfs
-rw-r--r-- 1 glassfish glassfish        263 Dec 23 13:41 _c0m.si
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 13:41 _c0n.cfe
-rw-r--r-- 1 glassfish glassfish      17897 Dec 23 13:41 _c0n.cfs
-rw-r--r-- 1 glassfish glassfish        263 Dec 23 13:41 _c0n.si
-rw-r--r-- 1 glassfish glassfish         57 Dec 23 13:43 _c0o_1.del
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 13:42 _c0o.cfe
-rw-r--r-- 1 glassfish glassfish      50578 Dec 23 13:42 _c0o.cfs
-rw-r--r-- 1 glassfish glassfish        263 Dec 23 13:42 _c0o.si
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 13:42 _c0p.cfe
-rw-r--r-- 1 glassfish glassfish      86320 Dec 23 13:42 _c0p.cfs
-rw-r--r-- 1 glassfish glassfish        263 Dec 23 13:42 _c0p.si
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 13:43 _c0q.cfe
-rw-r--r-- 1 glassfish glassfish      16508 Dec 23 13:43 _c0q.cfs
-rw-r--r-- 1 glassfish glassfish        263 Dec 23 13:43 _c0q.si
-rw-r--r-- 1 glassfish glassfish        350 Dec 23 13:43 _c0r.cfe
-rw-r--r-- 1 glassfish glassfish       5810 Dec 23 13:43 _c0r.cfs
-rw-r--r-- 1 glassfish glassfish        263 Dec 23 13:43 _c0r.si
-rw-r--r-- 1 glassfish glassfish          0 Dec 23 13:43 _c0s.fdt
-rw-r--r-- 1 glassfish glassfish          0 Dec 23 13:43 _c0s.fdx
-rw-r--r-- 1 glassfish glassfish       1583 Dec 23 13:43 segments_atq
-rw-r--r-- 1 glassfish glassfish         36 Dec 23 13:43 segments.gen
-rw-r--r-- 1 glassfish glassfish          0 Dec 22 12:33 write.lock

 Regards

Piotr

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message