You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by "Hoss Man (JIRA)" <ji...@apache.org> on 2013/04/13 01:06:16 UTC
[jira] [Commented] (SOLR-4709) dir lock error if reopening cores to
fast?
[ https://issues.apache.org/jira/browse/SOLR-4709?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13630731#comment-13630731 ]
Hoss Man commented on SOLR-4709:
--------------------------------
This is what i saw in my logs...
{noformat}
INFO - 2013-04-12 15:31:42.180; org.apache.solr.handler.SnapPuller; Starting download of configuration files from master: [{name=schema.xml, checksum=265618607, size=1508}]
INFO - 2013-04-12 15:31:42.182; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=filecontent&checksum=true&wt=filestream&cf=schema.xml&qt=/replication&generation=8} status=0 QTime=0
INFO - 2013-04-12 15:31:42.220; org.apache.solr.handler.SnapPuller; New index installed. Updating index properties... index=index.20130413063141945
INFO - 2013-04-12 15:31:42.220; org.apache.solr.handler.SnapPuller; removing old index directory MockDirWrapper(org.apache.lucene.store.RAMDirectory@3dc7a0ef lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@57df5e1f)
INFO - 2013-04-12 15:31:42.221; org.apache.solr.handler.SnapPuller; Configuration files are modified, core will be reloaded
INFO - 2013-04-12 15:31:42.221; org.apache.solr.handler.SnapPuller; removing old index directory MockDirWrapper(org.apache.lucene.store.RAMDirectory@3dc7a0ef lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@57df5e1f)
INFO - 2013-04-12 15:31:42.221; org.apache.solr.core.CoreContainer; Reloading SolrCore 'collection1' using instanceDir: /home/hossman/lucene/dev/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1365805897384/slave/collection1
INFO - 2013-04-12 15:31:42.221; org.apache.solr.update.DefaultSolrCoreState; Creating new IndexWriter...
INFO - 2013-04-12 15:31:42.221; org.apache.solr.update.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=collection1
INFO - 2013-04-12 15:31:42.222; org.apache.solr.update.DefaultSolrCoreState; Rollback old IndexWriter... core=collection1
INFO - 2013-04-12 15:31:42.222; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/home/hossman/lucene/dev/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1365805897384/slave/collection1/'
INFO - 2013-04-12 15:31:42.245; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
INFO - 2013-04-12 15:31:42.267; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
INFO - 2013-04-12 15:31:42.267; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
INFO - 2013-04-12 15:31:42.269; org.apache.solr.schema.IndexSchema; Schema name=test
INFO - 2013-04-12 15:31:42.274; org.apache.solr.core.SolrCore; New index directory detected: old=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1365805897384/slave/collection1/data/index.20130413063140843 new=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1365805897384/slave/collection1/data/index.20130413063141945
INFO - 2013-04-12 15:31:42.276; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=1
commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2d9472e2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6203f784),segFN=segments_8,generation=8,filenames=[_2_Pulsing41_0.doc, _5.fdt, _4.fnm, _3.fdt, _1.fnm, _2_Pulsing41_0.tim, _4.fdx, _5.nvm, _3.nvd, _0_Pulsing41_0.tim, _0_Pulsing41_0.tip, _2_Pulsing41_0.tip, _5.nvd, _3.nvm, _6.nvd, _1.nvm, _0.fnm, _6_Pulsing41_0.tim, _1.nvd, _6_Pulsing41_0.tip, _2.fdt, _6.nvm, _1_Pulsing41_0.doc, _2.fdx, _5.si, _1.fdx, _2.nvm, _1_Pulsing41_0.tip, _1.fdt, _1_Pulsing41_0.tim, _2.nvd, _4_Pulsing41_0.tip, _3.si, _4_Pulsing41_0.tim, _6.fdt, _3_Pulsing41_0.doc, _2.si, _6.fdx, _3.fnm, _6_Pulsing41_0.doc, _0.nvd, _3_Pulsing41_0.tim, _0.si, _3_Pulsing41_0.tip, _5.fnm, _4_Pulsing41_0.doc, _4.si, _4.fdt, _0.nvm, _2.fnm, _3.fdx, _0_Pulsing41_0.doc, _4.nvd, _5_Pulsing41_0.tim, segments_8, _1.si, _5.fdx, _6.fnm, _6.si, _0.fdx, _5_Pulsing41_0.doc, _4.nvm, _5_Pulsing41_0.tip, _0.fdt]
INFO - 2013-04-12 15:31:42.277; org.apache.solr.core.SolrDeletionPolicy; newest commit = 8[_2_Pulsing41_0.doc, _5.fdt, _4.fnm, _3.fdt, _1.fnm, _2_Pulsing41_0.tim, _4.fdx, _5.nvm, _3.nvd, _0_Pulsing41_0.tim, _0_Pulsing41_0.tip, _2_Pulsing41_0.tip, _5.nvd, _3.nvm, _6.nvd, _1.nvm, _0.fnm, _6_Pulsing41_0.tim, _1.nvd, _6_Pulsing41_0.tip, _2.fdt, _6.nvm, _1_Pulsing41_0.doc, _2.fdx, _5.si, _1.fdx, _2.nvm, _1_Pulsing41_0.tip, _1.fdt, _1_Pulsing41_0.tim, _2.nvd, _4_Pulsing41_0.tip, _3.si, _4_Pulsing41_0.tim, _6.fdt, _3_Pulsing41_0.doc, _2.si, _6.fdx, _3.fnm, _6_Pulsing41_0.doc, _0.nvd, _3_Pulsing41_0.tim, _0.si, _3_Pulsing41_0.tip, _5.fnm, _4_Pulsing41_0.doc, _4.si, _4.fdt, _0.nvm, _2.fnm, _3.fdx, _0_Pulsing41_0.doc, _4.nvd, _5_Pulsing41_0.tim, segments_8, _1.si, _5.fdx, _6.fnm, _6.si, _0.fdx, _5_Pulsing41_0.doc, _4.nvm, _5_Pulsing41_0.tip, _0.fdt]
INFO - 2013-04-12 15:31:42.277; org.apache.solr.update.DefaultSolrCoreState; New IndexWriter is ready to be used.
INFO - 2013-04-12 15:31:42.281; org.apache.solr.schema.IndexSchema; unique key field: id
INFO - 2013-04-12 15:31:42.282; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at /home/hossman/lucene/dev/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1365805897384/slave/collection1/, dataDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1365805897384/slave/collection1/data/
INFO - 2013-04-12 15:31:42.282; org.apache.solr.core.SolrCore; JMX monitoring not detected for core: collection1
INFO - 2013-04-12 15:31:42.282; org.apache.solr.core.SolrCore; New index directory detected: old=null new=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1365805897384/slave/collection1/data/index.20130413063141945
ERROR - 2013-04-12 15:31:42.282; org.apache.solr.core.SolrCore; [collection1] Solr index directory './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1365805897384/slave/collection1/data/index.20130413063141945' is locked. Throwing exception
INFO - 2013-04-12 15:31:42.282; org.apache.solr.core.SolrCore; [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@6fe131b5
INFO - 2013-04-12 15:31:42.282; org.apache.solr.core.SolrCore; [collection1] Closing main searcher on request.
ERROR - 2013-04-12 15:31:42.282; org.apache.solr.core.CoreContainer; Unable to reload core: collection1
org.apache.solr.common.SolrException: Index locked for write for core collection1
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:821)
at org.apache.solr.core.SolrCore.reload(SolrCore.java:408)
at org.apache.solr.core.CoreContainer.reload(CoreContainer.java:1108)
at org.apache.solr.handler.SnapPuller$2.run(SnapPuller.java:666)
Caused by: org.apache.lucene.store.LockObtainFailedException: Index locked for write for core collection1
at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:484)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:745)
... 3 more
ERROR - 2013-04-12 15:31:42.283; org.apache.solr.handler.SnapPuller$2; Could not reload core
org.apache.solr.common.SolrException: Unable to reload core: collection1
at org.apache.solr.core.CoreContainer.recordAndThrow(CoreContainer.java:1432)
at org.apache.solr.core.CoreContainer.reload(CoreContainer.java:1118)
at org.apache.solr.handler.SnapPuller$2.run(SnapPuller.java:666)
Caused by: org.apache.solr.common.SolrException: Index locked for write for core collection1
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:821)
at org.apache.solr.core.SolrCore.reload(SolrCore.java:408)
at org.apache.solr.core.CoreContainer.reload(CoreContainer.java:1108)
... 1 more
Caused by: org.apache.lucene.store.LockObtainFailedException: Index locked for write for core collection1
at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:484)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:745)
... 3 more
INFO - 2013-04-12 15:31:42.285; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@2093e93e main
INFO - 2013-04-12 15:31:42.286; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@2093e93e main{StandardDirectoryReader(segments_8:16:nrt _0(5.0):C16 _1(5.0):C64 _2(5.0):C159 _3(5.0):C154 _4(5.0):C107 _5(5.0):C37 _6(5.0):C124)}
INFO - 2013-04-12 15:31:42.286; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:58873/solr/replication&command=fetchindex&wait=true} status=0 QTime=349
INFO - 2013-04-12 15:31:42.287; org.apache.solr.core.CachingDirectoryFactory; looking to close ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1365805897384/slave/collection1/data/index.20130413063140843 [CachedDir<<refCount=0;path=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1365805897384/slave/collection1/data/index.20130413063140843;done=true>>]
INFO - 2013-04-12 15:31:42.287; org.apache.solr.core.CachingDirectoryFactory; Closing directory: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1365805897384/slave/collection1/data/index.20130413063140843
INFO - 2013-04-12 15:31:42.287; org.apache.solr.core.CachingDirectoryFactory; Removing directory before core close: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1365805897384/slave/collection1/data/index.20130413063140843
{noformat}
> dir lock error if reopening cores to fast?
> ------------------------------------------
>
> Key: SOLR-4709
> URL: https://issues.apache.org/jira/browse/SOLR-4709
> Project: Solr
> Issue Type: Bug
> Reporter: Hoss Man
>
> While testing my patch for SOLR-4629, i noticed a really random error that i traced back to the core reload (do to config file replication) failed because the directory was locked.
> From what i can tell, the lock checking code in the SolrCore constructor isn't even suppose to be used in the reload situation where there is a "prev" core, except that in SolrCore.reload there is this check...
> {noformat}
> if (!getNewIndexDir().equals(getIndexDir())) {
> // the directory is changing, don't pass on state
> prev = null;
> }
> {noformat}
> ..i'm not really sure i understand this logic, or what exactly the source of the problem is, or if the lock checking code should just be changed to work a differnet way completley, but it seemed worthy of tracking in it's own jira.
> log details to follow
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org