[jira] [Updated] (SOLR-2508) Master/Slave replication can leave slave in inconsistent state of NullPointerException in solrHighligher.java 102
[ https://issues.apache.org/jira/browse/SOLR-2508?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ] Xing Li updated SOLR-2508: -- Attachment: solrconfig.xml schema.xml > Master/Slave replication can leave slave in inconsistent state of > NullPointerException in solrHighligher.java 102 > -- > > Key: SOLR-2508 > URL: https://issues.apache.org/jira/browse/SOLR-2508 > Project: Solr > Issue Type: Bug > Components: highlighter, replication (java) >Affects Versions: 4.0 > Environment: Centos 5.6 with Java1.7.0b137 >Reporter: Xing Li > Attachments: schema.xml, solrconfig.xml > > > Using Solr 4/Trunk snapshot build of 5/10/2011. > Setup: > -- > 1) 1 Master + 4 Slaves > 2) Multicore setup with 8 cores. > 3) Replication Poll Interval: 00:30:20 > Summary of Issue: > --- > When a slave completes a replication pull from master, it will complete the > data index pull but > based on logs it appears subsequent index warming and other actions post > replication > cleanup leaves the core/db in an inconsistent state. > Frequency of occurrence: Very high but not 100%. I have 1 master and 4 slaves > and for each replication > pull cycle, around 50% of the gets affected. Each slave has 8 multi-cores but > the problem always affects this particular "mysolr_blogs" db/core. > Please note the "mysolr_blogs" data index is 1.4GB and the largest of the 8 > by a wide margin. > Attached is the schema.xml and solrconfig.xml for the "mysolr_blogs" core. > Temp fix: > - > 1) Stop and restart the solr server when this happens. > 2) Stop using automatic replication on this core. > Logging: > - > * begins automatic replication pull > {code} > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Master's version: 1302675975227, generation: 694 > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave's version: 1302675975222, generation: 692 > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Starting replication process > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Number of files in latest index in master: 10 > {code} > * 65 seconds past and I cut out the query logs in between. Here it's pulling > the 1.4GB "mysolr_blogs" index data. > {code} > May 10, 2011 10:18:45 PM org.apache.solr.handler.SnapPuller downloadIndexFiles > INFO: Skipping download for > /db/solr-master/multicore/mysolr_blogs/data/index/1.fnx > May 10, 2011 10:18:45 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Total time taken for download : 65 secs > May 10, 2011 10:18:45 PM org.apache.solr.core.SolrCore execute > INFO: [mysolr_users] webapp=/solr path=/select > params={sort=&indent=off&start=0&q=%2Buname:inlove*&q.op=and&hl.fl=*&facet.field=pcategoryid&facet.field=categoryid&facet.field=languageid&wt=json&hl=true&rows=51} > hits=0 status=0 QTime=1 > May 10, 2011 10:18:45 PM org.apache.solr.core.SolrCore execute > INFO: [mysolr_blogs] webapp=/solr path=/select/ params={q=solr} hits=0 > status=0 QTime=0 > May 10, 2011 10:18:45 PM org.apache.solr.core.SolrCore execute > INFO: [mysolr_blogs] webapp=/solr path=/select/ params={q=solr} hits=0 > status=0 QTime=0 > May 10, 2011 10:18:46 PM org.apache.solr.update.DirectUpdateHandler2 commit > INFO: start > commit(optimize=false,waitFlush=true,waitSearcher=true,expungeDeletes=false) > May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher > INFO: Opening Searcher@4f83f9df main > May 10, 2011 10:18:46 PM org.apache.solr.update.DirectUpdateHandler2 commit > INFO: end_commit_flush > May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher warm > INFO: autowarming Searcher@4f83f9df main from Searcher@5f7808af main > > fieldValueCache{lookups=22649,hits=22634,hitratio=0.99,inserts=5,evictions=0,size=5,warmupTime=0,cumulat
[jira] [Updated] (SOLR-2508) Master/Slave replication can leave slave in inconsistent state of NullPointerException in solrHighligher.java 102
[ https://issues.apache.org/jira/browse/SOLR-2508?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ] Xing Li updated SOLR-2508: -- Attachment: (was: solrconfig.xml) > Master/Slave replication can leave slave in inconsistent state of > NullPointerException in solrHighligher.java 102 > -- > > Key: SOLR-2508 > URL: https://issues.apache.org/jira/browse/SOLR-2508 > Project: Solr > Issue Type: Bug > Components: highlighter, replication (java) >Affects Versions: 4.0 > Environment: Centos 5.6 with Java1.7.0b137 >Reporter: Xing Li > > Using Solr 4/Trunk snapshot build of 5/10/2011. > Setup: > -- > 1) 1 Master + 4 Slaves > 2) Multicore setup with 8 cores. > 3) Replication Poll Interval: 00:30:20 > Summary of Issue: > --- > When a slave completes a replication pull from master, it will complete the > data index pull but > based on logs it appears subsequent index warming and other actions post > replication > cleanup leaves the core/db in an inconsistent state. > Frequency of occurrence: Very high but not 100%. I have 1 master and 4 slaves > and for each replication > pull cycle, around 50% of the gets affected. Each slave has 8 multi-cores but > the problem always affects this particular "mysolr_blogs" db/core. > Please note the "mysolr_blogs" data index is 1.4GB and the largest of the 8 > by a wide margin. > Attached is the schema.xml and solrconfig.xml for the "mysolr_blogs" core. > Temp fix: > - > 1) Stop and restart the solr server when this happens. > 2) Stop using automatic replication on this core. > Logging: > - > * begins automatic replication pull > {code} > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Master's version: 1302675975227, generation: 694 > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave's version: 1302675975222, generation: 692 > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Starting replication process > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Number of files in latest index in master: 10 > {code} > * 65 seconds past and I cut out the query logs in between. Here it's pulling > the 1.4GB "mysolr_blogs" index data. > {code} > May 10, 2011 10:18:45 PM org.apache.solr.handler.SnapPuller downloadIndexFiles > INFO: Skipping download for > /db/solr-master/multicore/mysolr_blogs/data/index/1.fnx > May 10, 2011 10:18:45 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Total time taken for download : 65 secs > May 10, 2011 10:18:45 PM org.apache.solr.core.SolrCore execute > INFO: [mysolr_users] webapp=/solr path=/select > params={sort=&indent=off&start=0&q=%2Buname:inlove*&q.op=and&hl.fl=*&facet.field=pcategoryid&facet.field=categoryid&facet.field=languageid&wt=json&hl=true&rows=51} > hits=0 status=0 QTime=1 > May 10, 2011 10:18:45 PM org.apache.solr.core.SolrCore execute > INFO: [mysolr_blogs] webapp=/solr path=/select/ params={q=solr} hits=0 > status=0 QTime=0 > May 10, 2011 10:18:45 PM org.apache.solr.core.SolrCore execute > INFO: [mysolr_blogs] webapp=/solr path=/select/ params={q=solr} hits=0 > status=0 QTime=0 > May 10, 2011 10:18:46 PM org.apache.solr.update.DirectUpdateHandler2 commit > INFO: start > commit(optimize=false,waitFlush=true,waitSearcher=true,expungeDeletes=false) > May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher > INFO: Opening Searcher@4f83f9df main > May 10, 2011 10:18:46 PM org.apache.solr.update.DirectUpdateHandler2 commit > INFO: end_commit_flush > May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher warm > INFO: autowarming Searcher@4f83f9df main from Searcher@5f7808af main > > fieldValueCache{lookups=22649,hits=22634,hitratio=0.99,inserts=5,evictions=0,size=5,warmupTime=0,cumulative_lookups=62507,cumulative_hits=62464,cumulative_hitratio=0.99,cum
[jira] [Updated] (SOLR-2508) Master/Slave replication can leave slave in inconsistent state of NullPointerException in solrHighligher.java 102
[ https://issues.apache.org/jira/browse/SOLR-2508?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ] Xing Li updated SOLR-2508: -- Attachment: solrconfig.xml schema.xml > Master/Slave replication can leave slave in inconsistent state of > NullPointerException in solrHighligher.java 102 > -- > > Key: SOLR-2508 > URL: https://issues.apache.org/jira/browse/SOLR-2508 > Project: Solr > Issue Type: Bug > Components: highlighter, replication (java) >Affects Versions: 4.0 > Environment: Centos 5.6 with Java1.7.0b137 >Reporter: Xing Li > > Using Solr 4/Trunk snapshot build of 5/10/2011. > Setup: > -- > 1) 1 Master + 4 Slaves > 2) Multicore setup with 8 cores. > 3) Replication Poll Interval: 00:30:20 > Summary of Issue: > --- > When a slave completes a replication pull from master, it will complete the > data index pull but > based on logs it appears subsequent index warming and other actions post > replication > cleanup leaves the core/db in an inconsistent state. > Frequency of occurrence: Very high but not 100%. I have 1 master and 4 slaves > and for each replication > pull cycle, around 50% of the gets affected. Each slave has 8 multi-cores but > the problem always affects this particular "mysolr_blogs" db/core. > Please note the "mysolr_blogs" data index is 1.4GB and the largest of the 8 > by a wide margin. > Attached is the schema.xml and solrconfig.xml for the "mysolr_blogs" core. > Temp fix: > - > 1) Stop and restart the solr server when this happens. > 2) Stop using automatic replication on this core. > Logging: > - > * begins automatic replication pull > {code} > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Master's version: 1302675975227, generation: 694 > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave's version: 1302675975222, generation: 692 > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Starting replication process > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Number of files in latest index in master: 10 > {code} > * 65 seconds past and I cut out the query logs in between. Here it's pulling > the 1.4GB "mysolr_blogs" index data. > {code} > May 10, 2011 10:18:45 PM org.apache.solr.handler.SnapPuller downloadIndexFiles > INFO: Skipping download for > /db/solr-master/multicore/mysolr_blogs/data/index/1.fnx > May 10, 2011 10:18:45 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Total time taken for download : 65 secs > May 10, 2011 10:18:45 PM org.apache.solr.core.SolrCore execute > INFO: [mysolr_users] webapp=/solr path=/select > params={sort=&indent=off&start=0&q=%2Buname:inlove*&q.op=and&hl.fl=*&facet.field=pcategoryid&facet.field=categoryid&facet.field=languageid&wt=json&hl=true&rows=51} > hits=0 status=0 QTime=1 > May 10, 2011 10:18:45 PM org.apache.solr.core.SolrCore execute > INFO: [mysolr_blogs] webapp=/solr path=/select/ params={q=solr} hits=0 > status=0 QTime=0 > May 10, 2011 10:18:45 PM org.apache.solr.core.SolrCore execute > INFO: [mysolr_blogs] webapp=/solr path=/select/ params={q=solr} hits=0 > status=0 QTime=0 > May 10, 2011 10:18:46 PM org.apache.solr.update.DirectUpdateHandler2 commit > INFO: start > commit(optimize=false,waitFlush=true,waitSearcher=true,expungeDeletes=false) > May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher > INFO: Opening Searcher@4f83f9df main > May 10, 2011 10:18:46 PM org.apache.solr.update.DirectUpdateHandler2 commit > INFO: end_commit_flush > May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher warm > INFO: autowarming Searcher@4f83f9df main from Searcher@5f7808af main > > fieldValueCache{lookups=22649,hits=22634,hitratio=0.99,inserts=5,evictions=0,size=5,warmupTime=0,cumulative_lookups=62507,cumulative_hits=62464,cumulative_h
[jira] [Updated] (SOLR-2508) Master/Slave replication can leave slave in inconsistent state of NullPointerException in solrHighligher.java 102
[ https://issues.apache.org/jira/browse/SOLR-2508?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ] Xing Li updated SOLR-2508: -- Attachment: (was: schema.xml) > Master/Slave replication can leave slave in inconsistent state of > NullPointerException in solrHighligher.java 102 > -- > > Key: SOLR-2508 > URL: https://issues.apache.org/jira/browse/SOLR-2508 > Project: Solr > Issue Type: Bug > Components: highlighter, replication (java) >Affects Versions: 4.0 > Environment: Centos 5.6 with Java1.7.0b137 >Reporter: Xing Li > > Using Solr 4/Trunk snapshot build of 5/10/2011. > Setup: > -- > 1) 1 Master + 4 Slaves > 2) Multicore setup with 8 cores. > 3) Replication Poll Interval: 00:30:20 > Summary of Issue: > --- > When a slave completes a replication pull from master, it will complete the > data index pull but > based on logs it appears subsequent index warming and other actions post > replication > cleanup leaves the core/db in an inconsistent state. > Frequency of occurrence: Very high but not 100%. I have 1 master and 4 slaves > and for each replication > pull cycle, around 50% of the gets affected. Each slave has 8 multi-cores but > the problem always affects this particular "mysolr_blogs" db/core. > Please note the "mysolr_blogs" data index is 1.4GB and the largest of the 8 > by a wide margin. > Attached is the schema.xml and solrconfig.xml for the "mysolr_blogs" core. > Temp fix: > - > 1) Stop and restart the solr server when this happens. > 2) Stop using automatic replication on this core. > Logging: > - > * begins automatic replication pull > {code} > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Master's version: 1302675975227, generation: 694 > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave in sync with master. > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Slave's version: 1302675975222, generation: 692 > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Starting replication process > May 10, 2011 10:17:40 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Number of files in latest index in master: 10 > {code} > * 65 seconds past and I cut out the query logs in between. Here it's pulling > the 1.4GB "mysolr_blogs" index data. > {code} > May 10, 2011 10:18:45 PM org.apache.solr.handler.SnapPuller downloadIndexFiles > INFO: Skipping download for > /db/solr-master/multicore/mysolr_blogs/data/index/1.fnx > May 10, 2011 10:18:45 PM org.apache.solr.handler.SnapPuller fetchLatestIndex > INFO: Total time taken for download : 65 secs > May 10, 2011 10:18:45 PM org.apache.solr.core.SolrCore execute > INFO: [mysolr_users] webapp=/solr path=/select > params={sort=&indent=off&start=0&q=%2Buname:inlove*&q.op=and&hl.fl=*&facet.field=pcategoryid&facet.field=categoryid&facet.field=languageid&wt=json&hl=true&rows=51} > hits=0 status=0 QTime=1 > May 10, 2011 10:18:45 PM org.apache.solr.core.SolrCore execute > INFO: [mysolr_blogs] webapp=/solr path=/select/ params={q=solr} hits=0 > status=0 QTime=0 > May 10, 2011 10:18:45 PM org.apache.solr.core.SolrCore execute > INFO: [mysolr_blogs] webapp=/solr path=/select/ params={q=solr} hits=0 > status=0 QTime=0 > May 10, 2011 10:18:46 PM org.apache.solr.update.DirectUpdateHandler2 commit > INFO: start > commit(optimize=false,waitFlush=true,waitSearcher=true,expungeDeletes=false) > May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher > INFO: Opening Searcher@4f83f9df main > May 10, 2011 10:18:46 PM org.apache.solr.update.DirectUpdateHandler2 commit > INFO: end_commit_flush > May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher warm > INFO: autowarming Searcher@4f83f9df main from Searcher@5f7808af main > > fieldValueCache{lookups=22649,hits=22634,hitratio=0.99,inserts=5,evictions=0,size=5,warmupTime=0,cumulative_lookups=62507,cumulative_hits=62464,cumulative_hitratio=0.99,cumulat