[jira] [Updated] (SOLR-2508) Master/Slave replication can leave slave in inconsistent state of NullPointerException in solrHighligher.java 102

2011-05-10 Thread Xing Li (JIRA)

 [ 
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

2011-05-10 Thread Xing Li (JIRA)

 [ 
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

2011-05-10 Thread Xing Li (JIRA)

 [ 
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

2011-05-10 Thread Xing Li (JIRA)

 [ 
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