3 Replies Latest reply on Apr 20, 2012 8:03 AM by matlach

    Replicated data not visible (Infinispan/JBoss/Hibernate Search/Lucene)

    charles.blaxland

      Hi all,

       

      I've been beating my head against this one for a while now, and not making any progress, so would appreciate any assistance.


      I have 2 clustered JBoss 6.1 nodes running a webapp that uses the Hibernate Search (3.4.2.FINAL) to do text searches using Lucene (3.6.0). Hibernate Search is configured to use a replicated Infinispan (4.2.1.FINAL) cache obtained via JNDI.

       

      The problem I'm seeing is that although changes seem to be replicated between the lucene caches, searches through the app do not return replicated results. That is, if I add an indexed entity containing the string "hazel" on node 1, I can successfully search for "hazel" on node 1 but not on node 2.

       

      Here's my Infinispan config (defined in jboss/server/default/deploy/cluster/infinispan-cache-registry.sar/infinispan-configs.xml). It's more or less a copy of what's provided with Hibernate Search as a default config.

       

      {code}

        <infinispan-config name="lucene" jndi-name="java:CacheManager/lucene">

          <alias>lucene-cache</alias>

          <infinispan xmlns="urn:infinispan:config:4.2">

          <global>

              <globalJmxStatistics enabled="true" allowDuplicateDomains="true" mBeanServerLookup="org.infinispan.jmx.JBossMBeanServerLookup" />

       

              <transport clusterName="${jboss.partition.name:DefaultPartition}-HibernateSearch-Infinispan-cluster" distributedSyncTimeout="17500">

                <properties>

                  <property name="stack" value="${jboss.default.jgroups.stack:udp}"/>

                </properties>

              </transport>

       

              <shutdown hookBehavior="DONT_REGISTER" />

          </global>

       

           <default>

              <locking

                  lockAcquisitionTimeout="20000"

                  writeSkewCheck="false"

                  concurrencyLevel="500"

                  useLockStriping="false" />

       

               <lazyDeserialization enabled="false" />

              <invocationBatching enabled="true" />

       

               <clustering

                  mode="replication">

                  <stateRetrieval

                      timeout="20000"

                      logFlushTimeout="30000"

                      fetchInMemoryState="true"

                      alwaysProvideInMemoryState="true" />

                  <sync replTimeout="20000" />

              </clustering>

       

               <jmxStatistics enabled="true" />

              <eviction maxEntries="-1" strategy="NONE" />

              <expiration maxIdle="-1" />

          </default>

       

           <namedCache name="LuceneIndexesMetadata">

              <clustering

                  mode="replication">

                  <stateRetrieval

                      fetchInMemoryState="true"

                      logFlushTimeout="30000" />

                  <sync replTimeout="25000" />

              </clustering>

          </namedCache>

       

          <namedCache name="LuceneIndexesData">

              <clustering

                  mode="replication">

                  <stateRetrieval

                      fetchInMemoryState="true"

                      logFlushTimeout="30000" />

                  <sync replTimeout="25000" />

              </clustering>

          </namedCache>

       

           <namedCache name="LuceneIndexesLocking">

              <clustering

                  mode="replication">

                  <stateRetrieval

                      fetchInMemoryState="true"

                      logFlushTimeout="30000" />

                  <sync replTimeout="25000" />

              </clustering>

          </namedCache>

          </infinispan>

        </infinispan-config>

      {code}

       

       

      The replication appears to be happening successfully. Here is the log from node1:

       

      {code}

      18:08:19,102 DEBUG [org.jgroups.protocols.FD] sending are-you-alive msg to localhost:1199 (own address=localhost:1299)

      18:08:19,108 DEBUG [org.jgroups.protocols.FD] sending are-you-alive msg to localhost:1199 (own address=localhost:1299)

      18:08:23,117 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start unmarshaller@1c86820 after retrieving marshaller from thread local

      18:08:23,117 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop unmarshaller@1c86820

      18:08:23,117 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] Calling perform() on PrepareCommand {gtx=GlobalTransaction:<localhost:1199>:20:remote, modifications=[PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2087, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=21946612}@1ecde5f, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}, PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2087, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=12113623}@1fb382a, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}, PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2202, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=26826445}@24797f, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}], onePhaseCommit=true, gtx=GlobalTransaction:<localhost:1199>:20:remote, cacheName='//localhost/myapp'}

      18:08:23,118 TRACE [org.infinispan.commands.tx.PrepareCommand] Invoking remotely originated prepare: PrepareCommand {gtx=GlobalTransaction:<localhost:1199>:20:remote, modifications=[PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2087, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=21946612}@1ecde5f, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}, PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2087, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=12113623}@1fb382a, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}, PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2202, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=26826445}@24797f, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}], onePhaseCommit=true, gtx=GlobalTransaction:<localhost:1199>:20:remote, cacheName='//localhost/myapp'} with invocation context: RemoteTxInvocationContext{flags=null}

      18:08:23,118 TRACE [org.infinispan.transaction.xa.RemoteTransaction] Adding key XnbyXy6vwz0pTu13Wb4jCA__ to tx GlobalTransaction:<localhost:1199>:20:remote

      18:08:23,120 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start unmarshaller@1c86820 after retrieving marshaller from thread local

      18:08:23,122 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop unmarshaller@1c86820

      18:08:23,122 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL acquired for '-1699438125'

      18:08:23,122 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL released for '-1699438125'

      18:08:23,122 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start unmarshaller@1c86820 after retrieving marshaller from thread local

      18:08:23,124 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop unmarshaller@1c86820

      18:08:23,124 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL acquired for '-1699438125'

      18:08:23,124 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL released for '-1699438125'

      18:08:23,125 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start unmarshaller@1c86820 after retrieving marshaller from thread local

      18:08:23,125 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop unmarshaller@1c86820

      18:08:23,130 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL acquired for '-1699438125'

      18:08:23,131 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL released for '-1699438125'

      18:08:23,131 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start marshaller@17d28d2 after retrieving marshaller from thread local

      18:08:23,131 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop marshaller@17d28d2

      18:08:23,993 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start unmarshaller@a4b228 after retrieving marshaller from thread local

      18:08:24,002 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop unmarshaller@a4b228

      18:08:24,002 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] Calling perform() on PrepareCommand {gtx=GlobalTransaction:<localhost:1199>:21:remote, modifications=[PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2202, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=2347159}@ac9eff, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}, PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2202, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=33272598}@faa1c0, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}, PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2064, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=4157732}@91669a, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}], onePhaseCommit=true, gtx=GlobalTransaction:<localhost:1199>:21:remote, cacheName='//localhost/myapp'}

      18:08:24,003 TRACE [org.infinispan.commands.tx.PrepareCommand] Invoking remotely originated prepare: PrepareCommand {gtx=GlobalTransaction:<localhost:1199>:21:remote, modifications=[PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2202, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=2347159}@ac9eff, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}, PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2202, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=33272598}@faa1c0, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}, PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2064, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=4157732}@91669a, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}], onePhaseCommit=true, gtx=GlobalTransaction:<localhost:1199>:21:remote, cacheName='//localhost/myapp'} with invocation context: RemoteTxInvocationContext{flags=null}

      18:08:24,003 TRACE [org.infinispan.transaction.xa.RemoteTransaction] Adding key XnbyXy6vwz0pTu13Wb4jCA__ to tx GlobalTransaction:<localhost:1199>:21:remote

      18:08:24,004 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start unmarshaller@a4b228 after retrieving marshaller from thread local

      18:08:24,005 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop unmarshaller@a4b228

      18:08:24,006 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL acquired for '-1699438125'

      18:08:24,006 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL released for '-1699438125'

      18:08:24,007 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start unmarshaller@a4b228 after retrieving marshaller from thread local

      18:08:24,017 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop unmarshaller@a4b228

      18:08:24,018 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL acquired for '-1699438125'

      18:08:24,030 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL released for '-1699438125'

      18:08:24,030 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start unmarshaller@a4b228 after retrieving marshaller from thread local

      18:08:24,031 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop unmarshaller@a4b228

      18:08:24,031 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL acquired for '-1699438125'

      18:08:24,031 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL released for '-1699438125'

      18:08:24,031 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start marshaller@1e733d6 after retrieving marshaller from thread local

      18:08:24,032 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop marshaller@1e733d6

      18:08:25,103 DEBUG [org.jgroups.protocols.FD] sending are-you-alive msg to localhost:1199 (own address=localhost:1299)

      18:08:25,110 DEBUG [org.jgroups.protocols.FD] sending are-you-alive msg to localhost:1199 (own address=localhost:1299)

      {code}

       

       

      And then on node 2 you can see inifinispan receiving the replicated messages:

       

      {code}

      18:08:19,108 DEBUG [org.jgroups.protocols.FD] sending are-you-alive msg to localhost:1199 (own address=localhost:1299)

      18:08:23,117 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start unmarshaller@1c86820 after retrieving marshaller from thread local

      18:08:23,117 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop unmarshaller@1c86820

      18:08:23,117 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] Calling perform() on PrepareCommand {gtx=GlobalTransaction:<localhost:1199>:20:remote, modifications=[PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2087, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=21946612}@1ecde5f, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}, PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2087, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=12113623}@1fb382a, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}, PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2202, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=26826445}@24797f, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}], onePhaseCommit=true, gtx=GlobalTransaction:<localhost:1199>:20:remote, cacheName='//localhost/myapp'}

      18:08:23,118 TRACE [org.infinispan.commands.tx.PrepareCommand] Invoking remotely originated prepare: PrepareCommand {gtx=GlobalTransaction:<localhost:1199>:20:remote, modifications=[PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2087, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=21946612}@1ecde5f, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}, PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2087, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=12113623}@1fb382a, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}, PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2202, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=26826445}@24797f, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}], onePhaseCommit=true, gtx=GlobalTransaction:<localhost:1199>:20:remote, cacheName='//localhost/myapp'} with invocation context: RemoteTxInvocationContext{flags=null}

      18:08:23,118 TRACE [org.infinispan.transaction.xa.RemoteTransaction] Adding key XnbyXy6vwz0pTu13Wb4jCA__ to tx GlobalTransaction:<localhost:1199>:20:remote

      18:08:23,120 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start unmarshaller@1c86820 after retrieving marshaller from thread local

      18:08:23,122 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop unmarshaller@1c86820

      18:08:23,122 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL acquired for '-1699438125'

      18:08:23,122 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL released for '-1699438125'

      18:08:23,122 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start unmarshaller@1c86820 after retrieving marshaller from thread local

      18:08:23,124 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop unmarshaller@1c86820

      18:08:23,124 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL acquired for '-1699438125'

      18:08:23,124 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL released for '-1699438125'

      18:08:23,125 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start unmarshaller@1c86820 after retrieving marshaller from thread local

      18:08:23,125 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop unmarshaller@1c86820

      18:08:23,130 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL acquired for '-1699438125'

      18:08:23,131 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL released for '-1699438125'

      18:08:23,131 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start marshaller@17d28d2 after retrieving marshaller from thread local

      18:08:23,131 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop marshaller@17d28d2

      18:08:23,993 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start unmarshaller@a4b228 after retrieving marshaller from thread local

      18:08:24,002 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop unmarshaller@a4b228

      18:08:24,002 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] Calling perform() on PrepareCommand {gtx=GlobalTransaction:<localhost:1199>:21:remote, modifications=[PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2202, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=2347159}@ac9eff, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}, PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2202, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=33272598}@faa1c0, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}, PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2064, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=4157732}@91669a, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}], onePhaseCommit=true, gtx=GlobalTransaction:<localhost:1199>:21:remote, cacheName='//localhost/myapp'}

      18:08:24,003 TRACE [org.infinispan.commands.tx.PrepareCommand] Invoking remotely originated prepare: PrepareCommand {gtx=GlobalTransaction:<localhost:1199>:21:remote, modifications=[PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2202, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=2347159}@ac9eff, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}, PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2202, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=33272598}@faa1c0, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}, PutKeyValueCommand{key=XnbyXy6vwz0pTu13Wb4jCA__, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2064, array=[2, 1, -92, 3, 20, 3, 18, 2, 4, 73, ..]}, cachedHashCode=4157732}@91669a, putIfAbsent=false, lifespanMillis=-1, maxIdleTimeMillis=-1}], onePhaseCommit=true, gtx=GlobalTransaction:<localhost:1199>:21:remote, cacheName='//localhost/myapp'} with invocation context: RemoteTxInvocationContext{flags=null}

      18:08:24,003 TRACE [org.infinispan.transaction.xa.RemoteTransaction] Adding key XnbyXy6vwz0pTu13Wb4jCA__ to tx GlobalTransaction:<localhost:1199>:21:remote

      18:08:24,004 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start unmarshaller@a4b228 after retrieving marshaller from thread local

      18:08:24,005 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop unmarshaller@a4b228

      18:08:24,006 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL acquired for '-1699438125'

      18:08:24,006 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL released for '-1699438125'

      18:08:24,007 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start unmarshaller@a4b228 after retrieving marshaller from thread local

      18:08:24,017 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop unmarshaller@a4b228

      18:08:24,018 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL acquired for '-1699438125'

      18:08:24,030 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL released for '-1699438125'

      18:08:24,030 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start unmarshaller@a4b228 after retrieving marshaller from thread local

      18:08:24,031 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop unmarshaller@a4b228

      18:08:24,031 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL acquired for '-1699438125'

      18:08:24,031 TRACE [org.infinispan.util.concurrent.locks.StripedLock] WL released for '-1699438125'

      18:08:24,031 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Start marshaller@1e733d6 after retrieving marshaller from thread local

      18:08:24,032 TRACE [org.infinispan.marshall.jboss.JBossMarshaller] Stop marshaller@1e733d6

      18:08:25,110 DEBUG [org.jgroups.protocols.FD] sending are-you-alive msg to localhost:1199 (own address=localhost:1299)

      {code}

       

       

      Funny thing is, it seems to only be a problem when I configure inifinispan through the JBoss infinispan-configs.xml and register it in JNDI. If I just run with the default Infinispan config supplied with HIbernate Search, which starts its own cache manager and doesn't use JNDI, all works as expected.

       

      I've tried remote debugging the app and stepping through the Hibernate Search / Lucene code, but have uncovered nothing suspicious so far - the data looks like it's been replicated across, its just that the lucene DirectoryReader doesn't pick it up. Any suggestions or tips as to how to debug this further would be much appreciated! Unfortunately I'm unable to do any major version upgrades of any of the libraries at this time.

       

      Thanks,

      Charles

        • 1. Re: Replicated data not visible (Infinispan/JBoss/Hibernate Search/Lucene)
          galder.zamarreno

          Could you attach the code your using to both, add data to the cache (please show pojos involved)?

           

          Could you also attach the code that's doing the queries?

          • 2. Re: Replicated data not visible (Infinispan/JBoss/Hibernate Search/Lucene)
            charles.blaxland

            Thanks for the reply Galder.

             

            We're using Hibernate Search, so "adding data to the cache" for us means simply saving a new entity using hibernate (entityManager.merge(entity)).

             

            Here's the code that does the search:

             

            {code}

                public List<User> findByOrganisationAndQueryKey(SearchParam searchParam, Organisation organisation) {

                        FullTextQuery query = createSearchQuery(searchParam.getQ());

                        query.enableFullTextFilter(ORGANISATION_ID_FILTER_NAME).setParameter(ORGANISATION_ID_FILTER_KEY, organisation.getId().toString());

                        query.setFirstResult(searchParam.getFirstResult()).setMaxResults(searchParam.getMaxResult());

                        SortField sortFieldLastName = new SortField("lastName", SortField.STRING);

                        SortField sortFieldFirstName = new SortField("firstName", SortField.STRING);

                        org.apache.lucene.search.Sort sort = new org.apache.lucene.search.Sort(sortFieldLastName, sortFieldFirstName);

                        query.setSort(sort);

                        return query.getResultList();

                }

             

                public FullTextQuery createSearchQuery(String keyword) {

                    FullTextEntityManager fullTextEntityManager = org.hibernate.search.jpa.Search.getFullTextEntityManager(getEntityManager());

                    QueryBuilder qb = fullTextEntityManager.getSearchFactory().buildQueryBuilder().forEntity(User.class).get();

                    String searchQuery = "*" + keyword.toLowerCase() + "*";

                    org.apache.lucene.search.Query luceneQuery = qb.keyword()

                            .wildcard()

                            .onField("username")

                            .andField("firstName")

                            .andField("lastName")

                            .matching(searchQuery)

                            .createQuery();

                    FullTextQuery fullTextQuery = fullTextEntityManager.createFullTextQuery(luceneQuery, User.class);

                    return fullTextQuery;

                }

            {code}

             

             

            Finally here's how we configure hibernate and hibernate search

             

            {code}

              <bean id="entityManagerFactory" class="org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean">

                <property name="persistenceUnitName" value="myapp" />

                <property name="dataSource" ref="dataSource" />

                <property name="persistenceXmlLocation" value="classpath:persistence-myapp.xml" />

                <property name="jpaDialect">

                  <bean class="org.springframework.orm.jpa.vendor.HibernateJpaDialect" />

                </property>

                <property name="jpaVendorAdapter">

                  <bean class="org.springframework.orm.jpa.vendor.HibernateJpaVendorAdapter">

                    <property name="showSql" value="${db.showSql}" />

                    <property name="generateDdl" value="${db.generateDdl}" />

                    <property name="database" value="${db.database}" />

                  </bean>

                </property>

                <property name="jpaPropertyMap">

                  <map>

                    <entry key="hibernate.hbm2ddl.auto" value="${db.hbm2ddl.auto}" />

                 <entry key="hibernate.cache.region.factory_class" value="${db.singleton_cache_factory}" />

                 <entry key="hibernate.cache.region.factory_class" value="${db.cache_factory}" />

                    <entry key="hibernate.cache.use_second_level_cache" value="${db.useSecondLevelCache}" />

                    <entry key="hibernate.cache.use_query_cache" value="${db.useQueryCache}" />

                    <entry key="hibernate.cache.provider_configuration_file_resource_path" value="/ehcache.xml" />

                    <entry key="hibernate.ejb.naming_strategy" value="org.hibernate.cfg.ImprovedNamingStrategy" />

                    <entry key="hibernate.search.indexing_strategy" value="${hibernate.search.indexing_strategy}" />

                    <entry key="hibernate.search.default.directory_provider" value="infinispan" />

                    <entry key="hibernate.search.infinispan.cachemanager_jndiname" value="java:CacheManager/lucene" />

                    <entry key="javax.persistence.validation.factory" value-ref="validator"/>

                    <entry key="hibernate.jdbc.batch_size" value="${db.batch_size}"/>

                      <entry key="hibernate.dialect" value="${db.hibernate.dialect}"/>

                    <entry key="hibernate.connection.isolation" value="${db.isolation}"/>

                  </map>

              </property>

              </bean>

             

               <bean id="transactionManager" class="org.springframework.orm.jpa.JpaTransactionManager">

                <property name="entityManagerFactory" ref="entityManagerFactory" />

              </bean>

            {code}

             

             

            Cheers,

            Charles

            • 3. Re: Replicated data not visible (Infinispan/JBoss/Hibernate Search/Lucene)
              matlach

              i had the same issue,

              i'm really not sure what it was, but when i investigated at this time, it seem to me that the lucene index was not updated after replication.

               

              as a 'workaround' i've used a clustered query instead which behaved correctly.

               

              see my other post about the issue :

              https://community.jboss.org/message/637262

               

              see my 2 jira posts as well :

              https://issues.jboss.org/browse/ISPN-1876

              https://issues.jboss.org/browse/ISPN-1893