Issues

ZF-3514: Zend_Framework_Search_Lucene throws XXX.del is not readable

Description

Possibly related to: http://framework.zend.com/issues/browse/ZF-2448

Occasionally (at seemingly random intervals), performing a query throws an exception such as, File '/search/lucene_index/_30_j.del' is not readable

If you look at the structure of /search/lucene_index/, there is a _30_k.del file but no _30_j.del file. It appears the delGen is being incremented incorrectly occasionally possibly.

The exception is raised from Zend_Search_Lucene_Index_SegmentInfo line 303. $delFile = $this->directory->getFileObject($this->_name . '' . base_convert($this->_delGen, 10, 36) . '.del');

For a temporary, quick fix, I have modified Zend_Search_Lucene_Index_SegmentInfo to touch the file before it attempts to getFileObject. 303 $delFile = $this->directory->touchFile($this->_name . '' . base_convert($this->delGen, 10, 36) . '.del'); 304 $delFile = $this->_directory->getFileObject($this->_name . '' . base_convert($this->_delGen, 10, 36) . '.del');

I have reproduced this bug in 1.5.1 and 1.5.2

Comments

This is a really bizarre bug. Indexing fails in the same place every time, and it's not dependent on the particular item being indexed, it's dependent on when it is indexed (e.g., the 720th item (just an example) fails no matter what the 720th item actually is). This isn't a memory issue as far as I can tell.

It should be noted that I have also reproduced this bug with a checkout of trunk at revision 10001.

Got the same bug here. It's weird... I have an app that's been live for over a year without problems. Only when I moved it to a new VPS this problem started to show. Would optimizing the index regularly prevent this bug from occurring?

Could you provide full stack trace for the exception? There are two different situations where the problem may occur (opening index and updating index just updated by another process).

I've encountered this issue before with our internal ZF app (also at seemingly random intervals). I can't seem to comment on the issue, though, so I'm posting a stack trace here (with some potentially sensitive info masked).

Hope it's useful.

 
exception 'Zend_Search_Lucene_Exception' with message 'File '***/data/search/lucene/_5kf_54.del' is not readable.' in ***/library/Zend/Search/Lucene/Storage/File/Filesystem.php:59
Stack trace:
#0 ***/library/Insight/Search/Index/Adapter/Lucene/Storage/File/Filesystem.php(27): Zend_Search_Lucene_Storage_File_Filesystem->__construct('/***...', 'r+b')
#1 ***/library/Insight/Search/Index/Adapter/Lucene/Storage/Directory/Filesystem.php(100): Insight_Search_Index_Adapter_Lucene_Storage_File_Filesystem->__construct('/***...')
#2 ***/library/Zend/Search/Lucene/Index/SegmentInfo.php(303): Insight_Search_Index_Adapter_Lucene_Storage_Directory_Filesystem->getFileObject('_5kf_54.del')
#3 ***/library/Zend/Search/Lucene.php(380): Zend_Search_Lucene_Index_SegmentInfo->__const in ***/library/Zend/Search/Lucene/Storage/File/Filesystem.php on line 59 

Thanks for the stacktrace Aaron, I don't have one sitting around anymore.

Alexander, if there are two possible situations, shouldn't we address both of the possibilities? Since the issue was appearing at seemingly random intervals for myself and others, we can't guarantee which one of the two conditions are occurring.

Aeron: Thanks!

Josh: There are two places where Zend_Search_Lucene_Index_SegmentInfo object is created using already existing index segment. I don't see what is the cause of the problem now, so stacktrace helps to define where the problem actualy appears.

I found where the problem was.

Segments updating (which may happen if some documents were deleted) and segments_xxx file updaing were performed separately. So there was a lack for index updating lock. It may cause the floowing actions sequence:

process1 performs segments updating and writes new del file 30_j.del -> process2 performs segments updating and writes new del file _30_k.del -> process2 performs segment updating and writes new segments_xxx (with the latest del file generation k for segment _30) -> process1 performs segment updating and writes new segments_xxx+1 (with the latest del file generation j for segment _30) -> process1 performs index directory cleanup and deletes all _30*.del file excepting the last -> latest segments_yyy refers del generation for segment _30 as _j, but index folder doesn't contain _30_j.del file => index is corrupted, exception is thrown.

Fixed for the trunk, release-1.5 and release-1.6 branches. Will be included into ZF 1.5.3 (should come within a week).

Updating for the 1.6.0 release.