Uploaded image for project: 'ModeShape'
  1. ModeShape
  2. MODE-1843

Indexing is throwing exceptions under heavy load, losing lock, concurrency issues when using Infinispan Directory

    XMLWordPrintable

Details

    • Bug
    • Resolution: Won't Do
    • Blocker
    • None
    • 3.1.3.Final
    • Clustering
    • None

    Description

      When using InfinispanDirectory for lucene index storage, and lucene as backend provider in cluster environment we should get instant index changes on all nodes.
      If you have two modeshape instances and you add nodes by hand in both instances, everything is working right (low concurrency, no errors).

      logs lok like that on each machine for single index update:

      2013-03-05 10:08:29,851 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (BaseLockFactory.java:71) - Lock prepared, not acquired: write.lock for index nodeinfo
      2013-03-05 10:08:29,853 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (BaseLuceneLock.java:66) - Lock: write.lock acquired for index: nodeinfo
      2013-03-05 10:08:29,854 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,854 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,854 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,855 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,855 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,855 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,855 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,855 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,855 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,855 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,855 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,855 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,856 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,856 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,856 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,856 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,856 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,856 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,857 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,859 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,859 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,860 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,860 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,860 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,860 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,860 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,865 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,865 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,865 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,865 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,865 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,866 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,866 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,866 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,866 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,866 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,866 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,866 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,868 TRACE [Hibernate Search: IndexWriter worker executor for nodeinfo-1] (InfinispanIndexOutput.java:80) - Opened new IndexOutput for file:_v.fdt in index: nodeinfo
      2013-03-05 10:08:29,869 TRACE [Hibernate Search: IndexWriter worker executor for nodeinfo-1] (InfinispanIndexOutput.java:80) - Opened new IndexOutput for file:_v.fdx in index: nodeinfo
      2013-03-05 10:08:29,870 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:183) - Storing segment chunk: _v.fdt|0|nodeinfo
      2013-03-05 10:08:29,874 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,876 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:99) - Updated file listing: added _v.fdt
      2013-03-05 10:08:29,877 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:213) - Closed IndexOutput for _v.fdt|M|nodeinfo
      2013-03-05 10:08:29,877 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:183) - Storing segment chunk: _v.fdx|0|nodeinfo
      2013-03-05 10:08:29,878 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,879 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:99) - Updated file listing: added _v.fdx
      2013-03-05 10:08:29,880 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:213) - Closed IndexOutput for _v.fdx|M|nodeinfo
      2013-03-05 10:08:29,881 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:80) - Opened new IndexOutput for file:_v.tis in index: nodeinfo
      2013-03-05 10:08:29,881 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:80) - Opened new IndexOutput for file:_v.tii in index: nodeinfo
      2013-03-05 10:08:29,881 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:80) - Opened new IndexOutput for file:_v.frq in index: nodeinfo
      2013-03-05 10:08:29,881 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:80) - Opened new IndexOutput for file:_v.prx in index: nodeinfo
      2013-03-05 10:08:29,882 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:183) - Storing segment chunk: _v.tis|0|nodeinfo
      2013-03-05 10:08:29,883 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,884 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:99) - Updated file listing: added _v.tis
      2013-03-05 10:08:29,885 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:213) - Closed IndexOutput for _v.tis|M|nodeinfo
      2013-03-05 10:08:29,885 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:183) - Storing segment chunk: _v.tii|0|nodeinfo
      2013-03-05 10:08:29,887 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,889 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:99) - Updated file listing: added _v.tii
      2013-03-05 10:08:29,890 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:213) - Closed IndexOutput for _v.tii|M|nodeinfo
      2013-03-05 10:08:29,891 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:183) - Storing segment chunk: _v.frq|0|nodeinfo
      2013-03-05 10:08:29,892 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,893 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:99) - Updated file listing: added _v.frq
      2013-03-05 10:08:29,894 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:213) - Closed IndexOutput for _v.frq|M|nodeinfo
      2013-03-05 10:08:29,895 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:183) - Storing segment chunk: _v.prx|0|nodeinfo
      2013-03-05 10:08:29,896 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,897 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:99) - Updated file listing: added _v.prx
      2013-03-05 10:08:29,900 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:213) - Closed IndexOutput for _v.prx|M|nodeinfo
      2013-03-05 10:08:29,900 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:80) - Opened new IndexOutput for file:_v.nrm in index: nodeinfo
      2013-03-05 10:08:29,900 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:183) - Storing segment chunk: _v.nrm|0|nodeinfo
      2013-03-05 10:08:29,901 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,902 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:99) - Updated file listing: added _v.nrm
      2013-03-05 10:08:29,903 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:213) - Closed IndexOutput for _v.nrm|M|nodeinfo
      2013-03-05 10:08:29,903 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:80) - Opened new IndexOutput for file:_v.fnm in index: nodeinfo
      2013-03-05 10:08:29,903 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:183) - Storing segment chunk: _v.fnm|0|nodeinfo
      2013-03-05 10:08:29,905 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,906 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:99) - Updated file listing: added _v.fnm
      2013-03-05 10:08:29,907 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:213) - Closed IndexOutput for _v.fnm|M|nodeinfo
      2013-03-05 10:08:29,907 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,907 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,908 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,908 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,908 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,908 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,909 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:80) - Opened new IndexOutput for file:_u_1.del in index: nodeinfo
      2013-03-05 10:08:29,909 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:183) - Storing segment chunk: _u_1.del|0|nodeinfo
      2013-03-05 10:08:29,910 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,911 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:99) - Updated file listing: added _u_1.del
      2013-03-05 10:08:29,913 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:213) - Closed IndexOutput for _u_1.del|M|nodeinfo
      2013-03-05 10:08:29,914 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,914 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,914 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,914 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,914 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,914 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,915 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,915 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,915 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,915 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,915 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,915 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,915 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,915 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,915 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,915 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,916 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,916 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,916 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,916 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,916 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,916 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,916 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,916 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,916 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,916 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,916 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,917 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,917 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,917 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,917 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:80) - Opened new IndexOutput for file:segments_v in index: nodeinfo
      2013-03-05 10:08:29,917 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:183) - Storing segment chunk: segments_v|0|nodeinfo
      2013-03-05 10:08:29,919 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,920 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:99) - Updated file listing: added segments_v
      2013-03-05 10:08:29,921 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:213) - Closed IndexOutput for segments_v|M|nodeinfo
      2013-03-05 10:08:29,921 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:80) - Opened new IndexOutput for file:segments.gen in index: nodeinfo
      2013-03-05 10:08:29,921 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:183) - Storing segment chunk: segments.gen|0|nodeinfo
      2013-03-05 10:08:29,922 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,923 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanIndexOutput.java:213) - Closed IndexOutput for segments.gen|M|nodeinfo
      2013-03-05 10:08:29,923 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:71) - Refreshed file listing view
      2013-03-05 10:08:29,925 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (FileListOperations.java:85) - Updated file listing: removed segments_u
      2013-03-05 10:08:29,926 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (DistributedSegmentReadLocker.java:179) - deleting metadata: segments_u|M|nodeinfo
      2013-03-05 10:08:29,928 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (DistributedSegmentReadLocker.java:184) - deleting chunk: segments_u|0|nodeinfo
      2013-03-05 10:08:29,929 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (DistributedSegmentReadLocker.java:190) - deleting readlock: segments_u|RL|nodeinfo
      2013-03-05 10:08:29,929 DEBUG [Hibernate Search: Index updates queue processor for index nodeinfo-1] (InfinispanDirectory.java:214) - Removed file: segments_u from index: nodeinfo
      2013-03-05 10:08:29,930 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (BaseLuceneLock.java:92) - Lock removed for index: nodeinfo
      

      If you have two modeshape instances and you add 40 nodes programaticly on each, index is keept by only one node all the time, after 3 to 15 updates usually, and I start getting this exception, for each index update:

      2013-03-05 10:32:04,446 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (BaseLockFactory.java:71) - Lock prepared, not acquired: write.lock for index nodeinfo
      2013-03-05 10:32:04,447 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (BaseLuceneLock.java:72) - Lock: write.lock not aquired for index: nodeinfo, was taken already.
      2013-03-05 10:32:05,448 TRACE [Hibernate Search: Index updates queue processor for index nodeinfo-1] (BaseLuceneLock.java:72) - Lock: write.lock not aquired for index: nodeinfo, was taken already.
      2013-03-05 10:32:05,448 ERROR [Hibernate Search: Index updates queue processor for index nodeinfo-1] (LogErrorHandler.java:83) - HSEARCH000058: Exception occurred org.apache.lucene.store.LockObtainFailedException: Lock obtain timed out: org.infinispan.lucene.locking.BaseLuceneLock@a38776
      Primary Failure:
      	Entity org.modeshape.jcr.query.lucene.basic.NodeInfo  Id de0a805619b7f2b99509e0-1daa-4cbf-ad14-7378bf58ce62  Work Type  org.hibernate.search.backend.AddLuceneWork
      Subsequent failures:
      	Entity org.modeshape.jcr.query.lucene.basic.NodeInfo  Id de0a805619b7f2/  Work Type  org.hibernate.search.backend.UpdateLuceneWork
      
      org.apache.lucene.store.LockObtainFailedException: Lock obtain timed out: org.infinispan.lucene.locking.BaseLuceneLock@a38776
      	at org.apache.lucene.store.Lock.obtain(Lock.java:84)
      	at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:1108)
      	at org.hibernate.search.backend.impl.lucene.IndexWriterHolder.createNewIndexWriter(IndexWriterHolder.java:127)
      	at org.hibernate.search.backend.impl.lucene.IndexWriterHolder.getIndexWriter(IndexWriterHolder.java:102)
      	at org.hibernate.search.backend.impl.lucene.AbstractWorkspaceImpl.getIndexWriter(AbstractWorkspaceImpl.java:119)
      	at org.hibernate.search.backend.impl.lucene.SharedIndexWorkspaceImpl.getIndexWriter(SharedIndexWorkspaceImpl.java:77)
      	at org.hibernate.search.backend.impl.lucene.LuceneBackendQueueTask.applyUpdates(LuceneBackendQueueTask.java:99)
      	at org.hibernate.search.backend.impl.lucene.LuceneBackendQueueTask.run(LuceneBackendQueueTask.java:67)
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
      	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
      	at java.util.concurrent.FutureTask.run(FutureTask.java:138)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
      	at java.lang.Thread.run(Thread.java:662)
      2013-03-05 10:32:05,449 ERROR [Hibernate Search: Index updates queue processor for index nodeinfo-1] (LuceneBackendQueueTask.java:101) - HSEARCH000072: Couldn't open the IndexWriter because of previous error: operation skipped, index ouf of sync!
      

      Only one node, one that's still keeping lock, is working well updating index all the time, but the 2nd is failing with this exception.
      When searching you get only nodes added by the first node, and few added by second.

      I know that there is workaround, and I can use master/slave jgroups/jms configuration for index updates, or have longer lock wait timeout.

      Update request should be somehow queued, or chance should be given for other nodes to do some changes, so one node under heavy load can't cause others to fail.

      How to reproduce:
      unpack https://issues.jboss.org/secure/attachment/12361073/modeshape-remote-infinispan-store-example.tar.gz, run in one console:
      mvn exec:java -Djava.net.preferIPv4Stack=true <nfile.txt >out2.txt
      then quickly in second console run:
      mvn exec:java -Djava.net.preferIPv4Stack=true <nfile.txt >out1.txt

      then see:
      cat out1.txt | grep Exception -B 2 -A 20
      and
      cat out2.txt | grep Exception -B 2 -A 20

      Attachments

        Issue Links

          Activity

            People

              Unassigned Unassigned
              pjakub_jira Jakub Pawłowski (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: