You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by "Xing Li (JIRA)" <ji...@apache.org> on 2011/05/11 08:52:48 UTC
[jira] [Created] (SOLR-2508) Master/Slave replication can leave
slave in inconsistent state of NullPointerException in solrHighligher.java
102
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 <init>
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,cumulative_inserts=15,cumulative_evictions=0,item_censorid={field=censorid,memSize=4755,tindexSize=0,time=30,phase1=30,nTerms=5,bigTerms=5,termInstances=0,uses=6350},item_genreid={field=genreid,memSize=16021464,tindexSize=41,time=101,phase1=93,nTerms=22,bigTerms=8,termInstances=946095,uses=6972},item_categoryid={field=categoryid,memSize=16042663,tindexSize=624,time=298,phase1=289,nTerms=6317,bigTerms=2,termInstances=3293460,uses=3410},item_pcategoryid={field=pcategoryid,memSize=16021287,tindexSize=41,time=33,phase1=24,nTerms=10,bigTerms=6,termInstances=202007,uses=3008},item_characterid={field=characterid,memSize=17435082,tindexSize=2755,time=1005,phase1=983,nTerms=27398,bigTerms=1,termInstances=4537318,uses=2899}}
May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher warm
INFO: autowarming result for Searcher@4f83f9df main
fieldValueCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=62507,cumulative_hits=62464,cumulative_hitratio=0.99,cumulative_inserts=15,cumulative_evictions=0}
May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher warm
INFO: autowarming Searcher@4f83f9df main from Searcher@5f7808af main
filterCache{lookups=164648,hits=163973,hitratio=0.99,inserts=6762,evictions=0,size=3337,warmupTime=1586,cumulative_lookups=455065,cumulative_hits=452914,cumulative_hitratio=0.99,cumulative_inserts=17617,cumulative_evictions=0}
May 10, 2011 10:18:46 PM org.apache.solr.core.SolrCore execute
INFO: [mysolr_blogs] webapp=/solr path=/select params={sort=&indent=off&hl.fl=*&wt=json&hl=true&rows=50&start=0&facet.query=words:[0+TO+5]&facet.query=words:[6+TO+*]&facet.query=words:[11+TO+*]&facet.query=words:[31+TO+*]&facet.query=words:[51+TO+*]&facet.query=words:[151+TO+*]&facet.query=words:[301+TO+*]&q=%2Btext:video&q.op=and&facet.field=languageid&facet.field=genreid&facet.field=statusid&facet.field=censorid&fq=categoryid:4947&fq=characterid:56615&fq=characterid:23376} hits=22 status=0 QTime=3
May 10, 2011 10:18:47 PM org.apache.solr.core.SolrCore execute
INFO: [mysolr_users] webapp=/solr path=/select params={sort=&indent=off&start=0&q=%2Buname:regless*&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:47 PM org.apache.solr.core.SolrCore execute
INFO: [mysolr_blogs] webapp=/solr path=/select params={sort=&indent=off&hl.fl=*&wt=json&hl=true&rows=50&start=0&facet.query=words:[0+TO+5]&facet.query=words:[6+TO+*]&facet.query=words:[11+TO+*]&facet.query=words:[31+TO+*]&facet.query=words:[51+TO+*]&facet.query=words:[151+TO+*]&facet.query=words:[301+TO+*]&q=%2Btext:a&q.op=and&facet.field=languageid&facet.field=genreid&facet.field=statusid&facet.field=censorid&fq=categoryid:512&fq=genreid:3&fq=characterid:893&fq=characterid:891} hits=46 status=0 QTime=8
May 10, 2011 10:18:47 PM org.apache.solr.core.SolrCore execute
INFO: [mysolr_blogs] webapp=/solr path=/select params={sort=&indent=off&hl.fl=*&wt=json&hl=true&rows=50&start=0&facet.query=words:[0+TO+5]&facet.query=words:[6+TO+*]&facet.query=words:[11+TO+*]&facet.query=words:[31+TO+*]&facet.query=words:[51+TO+*]&facet.query=words:[151+TO+*]&facet.query=words:[301+TO+*]&q=%2Btext:oc&q.op=and&facet.field=pcategoryid&facet.field=categoryid&facet.field=genreid&facet.field=statusid&facet.field=censorid&fq=languageid:1} hits=87186 status=0 QTime=33
May 10, 2011 10:18:47 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:47 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:47 PM org.apache.solr.search.SolrIndexSearcher warm
INFO: autowarming result for Searcher@4f83f9df main
filterCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=512,warmupTime=1715,cumulative_lookups=455141,cumulative_hits=452988,cumulative_hitratio=0.99,cumulative_inserts=17621,cumulative_evictions=0}
May 10, 2011 10:18:47 PM org.apache.solr.search.SolrIndexSearcher warm
INFO: autowarming Searcher@4f83f9df main from Searcher@5f7808af main
documentCache{lookups=395056,hits=235922,hitratio=0.59,inserts=159134,evictions=0,size=159134,warmupTime=0,cumulative_lookups=1081920,cumulative_hits=644938,cumulative_hitratio=0.59,cumulative_inserts=436982,cumulative_evictions=0}
May 10, 2011 10:18:47 PM org.apache.solr.search.SolrIndexSearcher warm
INFO: autowarming result for Searcher@4f83f9df main
documentCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=1081920,cumulative_hits=644938,cumulative_hitratio=0.59,cumulative_inserts=436982,cumulative_evictions=0}
May 10, 2011 10:18:47 PM org.apache.solr.core.SolrCore registerSearcher
INFO: [mysolr_blogs] Registered new searcher Searcher@4f83f9df main
May 10, 2011 10:18:47 PM org.apache.solr.search.SolrIndexSearcher close
INFO: Closing Searcher@5f7808af main
fieldValueCache{lookups=22657,hits=22642,hitratio=0.99,inserts=5,evictions=0,size=5,warmupTime=0,cumulative_lookups=62515,cumulative_hits=62472,cumulative_hitratio=0.99,cumulative_inserts=15,cumulative_evictions=0,item_censorid={field=censorid,memSize=4755,tindexSize=0,time=30,phase1=30,nTerms=5,bigTerms=5,termInstances=0,uses=6353},item_genreid={field=genreid,memSize=16021464,tindexSize=41,time=101,phase1=93,nTerms=22,bigTerms=8,termInstances=946095,uses=6975},item_categoryid={field=categoryid,memSize=16042663,tindexSize=624,time=298,phase1=289,nTerms=6317,bigTerms=2,termInstances=3293460,uses=3411},item_pcategoryid={field=pcategoryid,memSize=16021287,tindexSize=41,time=33,phase1=24,nTerms=10,bigTerms=6,termInstances=202007,uses=3009},item_characterid={field=characterid,memSize=17435082,tindexSize=2755,time=1005,phase1=983,nTerms=27398,bigTerms=1,termInstances=4537318,uses=2899}}
filterCache{lookups=164724,hits=164047,hitratio=0.99,inserts=6766,evictions=0,size=3339,warmupTime=1586,cumulative_lookups=455141,cumulative_hits=452988,cumulative_hitratio=0.99,cumulative_inserts=17621,cumulative_evictions=0}
documentCache{lookups=395056,hits=235922,hitratio=0.59,inserts=159134,evictions=0,size=159134,warmupTime=0,cumulative_lookups=1081920,cumulative_hits=644938,cumulative_hitratio=0.59,cumulative_inserts=436982,cumulative_evictions=0}
May 10, 2011 10:18:47 PM org.apache.solr.handler.SnapPuller doCommit
INFO: Force open index writer to make sure older index files get deleted
May 10, 2011 10:18:47 PM org.apache.solr.core.SolrDeletionPolicy onInit
INFO: SolrDeletionPolicy.onInit: commits:num=2
commit{dir=/db/solr-master/multicore/mysolr_blogs/data/index,segFN=segments_j8,version=1302675975222,generation=692,filenames=[_va_0.tiv, _va_0.tib, _va_0.frq, _va.fnm, _va.fdt, _va_0.prx, segments_j8, _va.nrm, _va.fdx, 1.fnx]
commit{dir=/db/solr-master/multicore/mysolr_blogs/data/index,segFN=segments_ja,version=1302675975227,generation=694,filenames=[_vc.nrm, _vc_0.prx, _vc_0.tib, segments_ja, _vc.fdx, _vc.fnm, _vc.fdt, _vc_0.frq, _vc_0.tiv, 1.fnx]
May 10, 2011 10:18:47 PM org.apache.solr.core.SolrDeletionPolicy updateCommits
INFO: newest commit = 1302675975227
May 10, 2011 10:18:48 PM org.apache.solr.request.UnInvertedField <init>
INFO: UnInverted multi-valued field {field=genreid,memSize=16021848,tindexSize=41,time=103,phase1=95,nTerms=22,bigTerms=8,termInstances=946118,uses=0}
May 10, 2011 10:18:48 PM org.apache.solr.request.UnInvertedField <init>
INFO: UnInverted multi-valued field {field=characterid,memSize=17435520,tindexSize=2751,time=409,phase1=389,nTerms=27399,bigTerms=1,termInstances=4537465,uses=0}
May 10, 2011 10:18:48 PM org.apache.solr.request.UnInvertedField <init>
INFO: UnInverted multi-valued field {field=censorid,memSize=4755,tindexSize=0,time=10,phase1=10,nTerms=5,bigTerms=5,termInstances=0,uses=0}
May 10, 2011 10:18:48 PM org.apache.solr.common.SolrException log
SEVERE: java.lang.NullPointerException
at java.util.LinkedList$ListItr.next(Unknown Source)
at org.apache.solr.highlight.SolrHighlighter.getHighlightFields(SolrHighlighter.java:102)
at org.apache.solr.highlight.DefaultSolrHighlighter.doHighlighting(DefaultSolrHighlighter.java:347)
at org.apache.solr.handler.component.HighlightComponent.process(HighlightComponent.java:121)
at org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:231)
at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:129)
at org.apache.solr.core.SolrCore.execute(SolrCore.java:1290)
at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:353)
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:248)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1212)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:399)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:450)
at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:928)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:549)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
at org.mortbay.jetty.bio.SocketConnector$Connection.run(SocketConnector.java:228)
at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)
May 10, 2011 10:18:48 PM org.apache.solr.common.SolrException log
SEVERE: java.lang.NullPointerException
at java.util.LinkedList$ListItr.next(Unknown Source)
at org.apache.solr.highlight.SolrHighlighter.getHighlightFields(SolrHighlighter.java:102)
at org.apache.solr.highlight.DefaultSolrHighlighter.doHighlighting(DefaultSolrHighlighter.java:347)
at org.apache.solr.handler.component.HighlightComponent.process(HighlightComponent.java:121)
at org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:231)
at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:129)
at org.apache.solr.core.SolrCore.execute(SolrCore.java:1290)
at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:353)
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:248)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1212)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:399)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:450)
at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:928)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:549)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
at org.mortbay.jetty.bio.SocketConnector$Connection.run(SocketConnector.java:228)
at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)
{code}
* After this point. "mysolr_blogs" will continue to throw 500 null errors on searches
--
This message is automatically generated by JIRA.
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
[jira] [Updated] (SOLR-2508) Master/Slave replication can leave
slave in inconsistent state of NullPointerException in solrHighligher.java
102
Posted by "Xing Li (JIRA)" <ji...@apache.org>.
[ 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 <init>
> 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,cumulative_inserts=15,cumulative_evictions=0,item_censorid={field=censorid,memSize=4755,tindexSize=0,time=30,phase1=30,nTerms=5,bigTerms=5,termInstances=0,uses=6350},item_genreid={field=genreid,memSize=16021464,tindexSize=41,time=101,phase1=93,nTerms=22,bigTerms=8,termInstances=946095,uses=6972},item_categoryid={field=categoryid,memSize=16042663,tindexSize=624,time=298,phase1=289,nTerms=6317,bigTerms=2,termInstances=3293460,uses=3410},item_pcategoryid={field=pcategoryid,memSize=16021287,tindexSize=41,time=33,phase1=24,nTerms=10,bigTerms=6,termInstances=202007,uses=3008},item_characterid={field=characterid,memSize=17435082,tindexSize=2755,time=1005,phase1=983,nTerms=27398,bigTerms=1,termInstances=4537318,uses=2899}}
> May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming result for Searcher@4f83f9df main
> fieldValueCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=62507,cumulative_hits=62464,cumulative_hitratio=0.99,cumulative_inserts=15,cumulative_evictions=0}
> May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming Searcher@4f83f9df main from Searcher@5f7808af main
> filterCache{lookups=164648,hits=163973,hitratio=0.99,inserts=6762,evictions=0,size=3337,warmupTime=1586,cumulative_lookups=455065,cumulative_hits=452914,cumulative_hitratio=0.99,cumulative_inserts=17617,cumulative_evictions=0}
> May 10, 2011 10:18:46 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_blogs] webapp=/solr path=/select params={sort=&indent=off&hl.fl=*&wt=json&hl=true&rows=50&start=0&facet.query=words:[0+TO+5]&facet.query=words:[6+TO+*]&facet.query=words:[11+TO+*]&facet.query=words:[31+TO+*]&facet.query=words:[51+TO+*]&facet.query=words:[151+TO+*]&facet.query=words:[301+TO+*]&q=%2Btext:video&q.op=and&facet.field=languageid&facet.field=genreid&facet.field=statusid&facet.field=censorid&fq=categoryid:4947&fq=characterid:56615&fq=characterid:23376} hits=22 status=0 QTime=3
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_users] webapp=/solr path=/select params={sort=&indent=off&start=0&q=%2Buname:regless*&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:47 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_blogs] webapp=/solr path=/select params={sort=&indent=off&hl.fl=*&wt=json&hl=true&rows=50&start=0&facet.query=words:[0+TO+5]&facet.query=words:[6+TO+*]&facet.query=words:[11+TO+*]&facet.query=words:[31+TO+*]&facet.query=words:[51+TO+*]&facet.query=words:[151+TO+*]&facet.query=words:[301+TO+*]&q=%2Btext:a&q.op=and&facet.field=languageid&facet.field=genreid&facet.field=statusid&facet.field=censorid&fq=categoryid:512&fq=genreid:3&fq=characterid:893&fq=characterid:891} hits=46 status=0 QTime=8
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_blogs] webapp=/solr path=/select params={sort=&indent=off&hl.fl=*&wt=json&hl=true&rows=50&start=0&facet.query=words:[0+TO+5]&facet.query=words:[6+TO+*]&facet.query=words:[11+TO+*]&facet.query=words:[31+TO+*]&facet.query=words:[51+TO+*]&facet.query=words:[151+TO+*]&facet.query=words:[301+TO+*]&q=%2Btext:oc&q.op=and&facet.field=pcategoryid&facet.field=categoryid&facet.field=genreid&facet.field=statusid&facet.field=censorid&fq=languageid:1} hits=87186 status=0 QTime=33
> May 10, 2011 10:18:47 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:47 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:47 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming result for Searcher@4f83f9df main
> filterCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=512,warmupTime=1715,cumulative_lookups=455141,cumulative_hits=452988,cumulative_hitratio=0.99,cumulative_inserts=17621,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming Searcher@4f83f9df main from Searcher@5f7808af main
> documentCache{lookups=395056,hits=235922,hitratio=0.59,inserts=159134,evictions=0,size=159134,warmupTime=0,cumulative_lookups=1081920,cumulative_hits=644938,cumulative_hitratio=0.59,cumulative_inserts=436982,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming result for Searcher@4f83f9df main
> documentCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=1081920,cumulative_hits=644938,cumulative_hitratio=0.59,cumulative_inserts=436982,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrCore registerSearcher
> INFO: [mysolr_blogs] Registered new searcher Searcher@4f83f9df main
> May 10, 2011 10:18:47 PM org.apache.solr.search.SolrIndexSearcher close
> INFO: Closing Searcher@5f7808af main
> fieldValueCache{lookups=22657,hits=22642,hitratio=0.99,inserts=5,evictions=0,size=5,warmupTime=0,cumulative_lookups=62515,cumulative_hits=62472,cumulative_hitratio=0.99,cumulative_inserts=15,cumulative_evictions=0,item_censorid={field=censorid,memSize=4755,tindexSize=0,time=30,phase1=30,nTerms=5,bigTerms=5,termInstances=0,uses=6353},item_genreid={field=genreid,memSize=16021464,tindexSize=41,time=101,phase1=93,nTerms=22,bigTerms=8,termInstances=946095,uses=6975},item_categoryid={field=categoryid,memSize=16042663,tindexSize=624,time=298,phase1=289,nTerms=6317,bigTerms=2,termInstances=3293460,uses=3411},item_pcategoryid={field=pcategoryid,memSize=16021287,tindexSize=41,time=33,phase1=24,nTerms=10,bigTerms=6,termInstances=202007,uses=3009},item_characterid={field=characterid,memSize=17435082,tindexSize=2755,time=1005,phase1=983,nTerms=27398,bigTerms=1,termInstances=4537318,uses=2899}}
> filterCache{lookups=164724,hits=164047,hitratio=0.99,inserts=6766,evictions=0,size=3339,warmupTime=1586,cumulative_lookups=455141,cumulative_hits=452988,cumulative_hitratio=0.99,cumulative_inserts=17621,cumulative_evictions=0}
> documentCache{lookups=395056,hits=235922,hitratio=0.59,inserts=159134,evictions=0,size=159134,warmupTime=0,cumulative_lookups=1081920,cumulative_hits=644938,cumulative_hitratio=0.59,cumulative_inserts=436982,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.handler.SnapPuller doCommit
> INFO: Force open index writer to make sure older index files get deleted
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrDeletionPolicy onInit
> INFO: SolrDeletionPolicy.onInit: commits:num=2
> commit{dir=/db/solr-master/multicore/mysolr_blogs/data/index,segFN=segments_j8,version=1302675975222,generation=692,filenames=[_va_0.tiv, _va_0.tib, _va_0.frq, _va.fnm, _va.fdt, _va_0.prx, segments_j8, _va.nrm, _va.fdx, 1.fnx]
> commit{dir=/db/solr-master/multicore/mysolr_blogs/data/index,segFN=segments_ja,version=1302675975227,generation=694,filenames=[_vc.nrm, _vc_0.prx, _vc_0.tib, segments_ja, _vc.fdx, _vc.fnm, _vc.fdt, _vc_0.frq, _vc_0.tiv, 1.fnx]
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrDeletionPolicy updateCommits
> INFO: newest commit = 1302675975227
> May 10, 2011 10:18:48 PM org.apache.solr.request.UnInvertedField <init>
> INFO: UnInverted multi-valued field {field=genreid,memSize=16021848,tindexSize=41,time=103,phase1=95,nTerms=22,bigTerms=8,termInstances=946118,uses=0}
> May 10, 2011 10:18:48 PM org.apache.solr.request.UnInvertedField <init>
> INFO: UnInverted multi-valued field {field=characterid,memSize=17435520,tindexSize=2751,time=409,phase1=389,nTerms=27399,bigTerms=1,termInstances=4537465,uses=0}
> May 10, 2011 10:18:48 PM org.apache.solr.request.UnInvertedField <init>
> INFO: UnInverted multi-valued field {field=censorid,memSize=4755,tindexSize=0,time=10,phase1=10,nTerms=5,bigTerms=5,termInstances=0,uses=0}
> May 10, 2011 10:18:48 PM org.apache.solr.common.SolrException log
> SEVERE: java.lang.NullPointerException
> at java.util.LinkedList$ListItr.next(Unknown Source)
> at org.apache.solr.highlight.SolrHighlighter.getHighlightFields(SolrHighlighter.java:102)
> at org.apache.solr.highlight.DefaultSolrHighlighter.doHighlighting(DefaultSolrHighlighter.java:347)
> at org.apache.solr.handler.component.HighlightComponent.process(HighlightComponent.java:121)
> at org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:231)
> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:129)
> at org.apache.solr.core.SolrCore.execute(SolrCore.java:1290)
> at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:353)
> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:248)
> at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1212)
> at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:399)
> at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
> at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
> at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
> at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:450)
> at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
> at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
> at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
> at org.mortbay.jetty.Server.handle(Server.java:326)
> at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
> at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:928)
> at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:549)
> at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
> at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
> at org.mortbay.jetty.bio.SocketConnector$Connection.run(SocketConnector.java:228)
> at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)
> May 10, 2011 10:18:48 PM org.apache.solr.common.SolrException log
> SEVERE: java.lang.NullPointerException
> at java.util.LinkedList$ListItr.next(Unknown Source)
> at org.apache.solr.highlight.SolrHighlighter.getHighlightFields(SolrHighlighter.java:102)
> at org.apache.solr.highlight.DefaultSolrHighlighter.doHighlighting(DefaultSolrHighlighter.java:347)
> at org.apache.solr.handler.component.HighlightComponent.process(HighlightComponent.java:121)
> at org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:231)
> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:129)
> at org.apache.solr.core.SolrCore.execute(SolrCore.java:1290)
> at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:353)
> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:248)
> at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1212)
> at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:399)
> at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
> at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
> at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
> at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:450)
> at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
> at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
> at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
> at org.mortbay.jetty.Server.handle(Server.java:326)
> at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
> at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:928)
> at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:549)
> at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
> at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
> at org.mortbay.jetty.bio.SocketConnector$Connection.run(SocketConnector.java:228)
> at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)
> {code}
> * After this point. "mysolr_blogs" will continue to throw 500 null errors on searches
--
This message is automatically generated by JIRA.
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
[jira] [Updated] (SOLR-2508) Master/Slave replication can leave
slave in inconsistent state of NullPointerException in solrHighligher.java
102
Posted by "Xing Li (JIRA)" <ji...@apache.org>.
[ 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 <init>
> 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,cumulative_inserts=15,cumulative_evictions=0,item_censorid={field=censorid,memSize=4755,tindexSize=0,time=30,phase1=30,nTerms=5,bigTerms=5,termInstances=0,uses=6350},item_genreid={field=genreid,memSize=16021464,tindexSize=41,time=101,phase1=93,nTerms=22,bigTerms=8,termInstances=946095,uses=6972},item_categoryid={field=categoryid,memSize=16042663,tindexSize=624,time=298,phase1=289,nTerms=6317,bigTerms=2,termInstances=3293460,uses=3410},item_pcategoryid={field=pcategoryid,memSize=16021287,tindexSize=41,time=33,phase1=24,nTerms=10,bigTerms=6,termInstances=202007,uses=3008},item_characterid={field=characterid,memSize=17435082,tindexSize=2755,time=1005,phase1=983,nTerms=27398,bigTerms=1,termInstances=4537318,uses=2899}}
> May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming result for Searcher@4f83f9df main
> fieldValueCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=62507,cumulative_hits=62464,cumulative_hitratio=0.99,cumulative_inserts=15,cumulative_evictions=0}
> May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming Searcher@4f83f9df main from Searcher@5f7808af main
> filterCache{lookups=164648,hits=163973,hitratio=0.99,inserts=6762,evictions=0,size=3337,warmupTime=1586,cumulative_lookups=455065,cumulative_hits=452914,cumulative_hitratio=0.99,cumulative_inserts=17617,cumulative_evictions=0}
> May 10, 2011 10:18:46 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_blogs] webapp=/solr path=/select params={sort=&indent=off&hl.fl=*&wt=json&hl=true&rows=50&start=0&facet.query=words:[0+TO+5]&facet.query=words:[6+TO+*]&facet.query=words:[11+TO+*]&facet.query=words:[31+TO+*]&facet.query=words:[51+TO+*]&facet.query=words:[151+TO+*]&facet.query=words:[301+TO+*]&q=%2Btext:video&q.op=and&facet.field=languageid&facet.field=genreid&facet.field=statusid&facet.field=censorid&fq=categoryid:4947&fq=characterid:56615&fq=characterid:23376} hits=22 status=0 QTime=3
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_users] webapp=/solr path=/select params={sort=&indent=off&start=0&q=%2Buname:regless*&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:47 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_blogs] webapp=/solr path=/select params={sort=&indent=off&hl.fl=*&wt=json&hl=true&rows=50&start=0&facet.query=words:[0+TO+5]&facet.query=words:[6+TO+*]&facet.query=words:[11+TO+*]&facet.query=words:[31+TO+*]&facet.query=words:[51+TO+*]&facet.query=words:[151+TO+*]&facet.query=words:[301+TO+*]&q=%2Btext:a&q.op=and&facet.field=languageid&facet.field=genreid&facet.field=statusid&facet.field=censorid&fq=categoryid:512&fq=genreid:3&fq=characterid:893&fq=characterid:891} hits=46 status=0 QTime=8
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_blogs] webapp=/solr path=/select params={sort=&indent=off&hl.fl=*&wt=json&hl=true&rows=50&start=0&facet.query=words:[0+TO+5]&facet.query=words:[6+TO+*]&facet.query=words:[11+TO+*]&facet.query=words:[31+TO+*]&facet.query=words:[51+TO+*]&facet.query=words:[151+TO+*]&facet.query=words:[301+TO+*]&q=%2Btext:oc&q.op=and&facet.field=pcategoryid&facet.field=categoryid&facet.field=genreid&facet.field=statusid&facet.field=censorid&fq=languageid:1} hits=87186 status=0 QTime=33
> May 10, 2011 10:18:47 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:47 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:47 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming result for Searcher@4f83f9df main
> filterCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=512,warmupTime=1715,cumulative_lookups=455141,cumulative_hits=452988,cumulative_hitratio=0.99,cumulative_inserts=17621,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming Searcher@4f83f9df main from Searcher@5f7808af main
> documentCache{lookups=395056,hits=235922,hitratio=0.59,inserts=159134,evictions=0,size=159134,warmupTime=0,cumulative_lookups=1081920,cumulative_hits=644938,cumulative_hitratio=0.59,cumulative_inserts=436982,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming result for Searcher@4f83f9df main
> documentCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=1081920,cumulative_hits=644938,cumulative_hitratio=0.59,cumulative_inserts=436982,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrCore registerSearcher
> INFO: [mysolr_blogs] Registered new searcher Searcher@4f83f9df main
> May 10, 2011 10:18:47 PM org.apache.solr.search.SolrIndexSearcher close
> INFO: Closing Searcher@5f7808af main
> fieldValueCache{lookups=22657,hits=22642,hitratio=0.99,inserts=5,evictions=0,size=5,warmupTime=0,cumulative_lookups=62515,cumulative_hits=62472,cumulative_hitratio=0.99,cumulative_inserts=15,cumulative_evictions=0,item_censorid={field=censorid,memSize=4755,tindexSize=0,time=30,phase1=30,nTerms=5,bigTerms=5,termInstances=0,uses=6353},item_genreid={field=genreid,memSize=16021464,tindexSize=41,time=101,phase1=93,nTerms=22,bigTerms=8,termInstances=946095,uses=6975},item_categoryid={field=categoryid,memSize=16042663,tindexSize=624,time=298,phase1=289,nTerms=6317,bigTerms=2,termInstances=3293460,uses=3411},item_pcategoryid={field=pcategoryid,memSize=16021287,tindexSize=41,time=33,phase1=24,nTerms=10,bigTerms=6,termInstances=202007,uses=3009},item_characterid={field=characterid,memSize=17435082,tindexSize=2755,time=1005,phase1=983,nTerms=27398,bigTerms=1,termInstances=4537318,uses=2899}}
> filterCache{lookups=164724,hits=164047,hitratio=0.99,inserts=6766,evictions=0,size=3339,warmupTime=1586,cumulative_lookups=455141,cumulative_hits=452988,cumulative_hitratio=0.99,cumulative_inserts=17621,cumulative_evictions=0}
> documentCache{lookups=395056,hits=235922,hitratio=0.59,inserts=159134,evictions=0,size=159134,warmupTime=0,cumulative_lookups=1081920,cumulative_hits=644938,cumulative_hitratio=0.59,cumulative_inserts=436982,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.handler.SnapPuller doCommit
> INFO: Force open index writer to make sure older index files get deleted
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrDeletionPolicy onInit
> INFO: SolrDeletionPolicy.onInit: commits:num=2
> commit{dir=/db/solr-master/multicore/mysolr_blogs/data/index,segFN=segments_j8,version=1302675975222,generation=692,filenames=[_va_0.tiv, _va_0.tib, _va_0.frq, _va.fnm, _va.fdt, _va_0.prx, segments_j8, _va.nrm, _va.fdx, 1.fnx]
> commit{dir=/db/solr-master/multicore/mysolr_blogs/data/index,segFN=segments_ja,version=1302675975227,generation=694,filenames=[_vc.nrm, _vc_0.prx, _vc_0.tib, segments_ja, _vc.fdx, _vc.fnm, _vc.fdt, _vc_0.frq, _vc_0.tiv, 1.fnx]
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrDeletionPolicy updateCommits
> INFO: newest commit = 1302675975227
> May 10, 2011 10:18:48 PM org.apache.solr.request.UnInvertedField <init>
> INFO: UnInverted multi-valued field {field=genreid,memSize=16021848,tindexSize=41,time=103,phase1=95,nTerms=22,bigTerms=8,termInstances=946118,uses=0}
> May 10, 2011 10:18:48 PM org.apache.solr.request.UnInvertedField <init>
> INFO: UnInverted multi-valued field {field=characterid,memSize=17435520,tindexSize=2751,time=409,phase1=389,nTerms=27399,bigTerms=1,termInstances=4537465,uses=0}
> May 10, 2011 10:18:48 PM org.apache.solr.request.UnInvertedField <init>
> INFO: UnInverted multi-valued field {field=censorid,memSize=4755,tindexSize=0,time=10,phase1=10,nTerms=5,bigTerms=5,termInstances=0,uses=0}
> May 10, 2011 10:18:48 PM org.apache.solr.common.SolrException log
> SEVERE: java.lang.NullPointerException
> at java.util.LinkedList$ListItr.next(Unknown Source)
> at org.apache.solr.highlight.SolrHighlighter.getHighlightFields(SolrHighlighter.java:102)
> at org.apache.solr.highlight.DefaultSolrHighlighter.doHighlighting(DefaultSolrHighlighter.java:347)
> at org.apache.solr.handler.component.HighlightComponent.process(HighlightComponent.java:121)
> at org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:231)
> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:129)
> at org.apache.solr.core.SolrCore.execute(SolrCore.java:1290)
> at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:353)
> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:248)
> at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1212)
> at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:399)
> at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
> at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
> at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
> at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:450)
> at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
> at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
> at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
> at org.mortbay.jetty.Server.handle(Server.java:326)
> at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
> at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:928)
> at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:549)
> at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
> at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
> at org.mortbay.jetty.bio.SocketConnector$Connection.run(SocketConnector.java:228)
> at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)
> May 10, 2011 10:18:48 PM org.apache.solr.common.SolrException log
> SEVERE: java.lang.NullPointerException
> at java.util.LinkedList$ListItr.next(Unknown Source)
> at org.apache.solr.highlight.SolrHighlighter.getHighlightFields(SolrHighlighter.java:102)
> at org.apache.solr.highlight.DefaultSolrHighlighter.doHighlighting(DefaultSolrHighlighter.java:347)
> at org.apache.solr.handler.component.HighlightComponent.process(HighlightComponent.java:121)
> at org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:231)
> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:129)
> at org.apache.solr.core.SolrCore.execute(SolrCore.java:1290)
> at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:353)
> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:248)
> at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1212)
> at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:399)
> at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
> at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
> at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
> at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:450)
> at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
> at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
> at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
> at org.mortbay.jetty.Server.handle(Server.java:326)
> at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
> at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:928)
> at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:549)
> at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
> at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
> at org.mortbay.jetty.bio.SocketConnector$Connection.run(SocketConnector.java:228)
> at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)
> {code}
> * After this point. "mysolr_blogs" will continue to throw 500 null errors on searches
--
This message is automatically generated by JIRA.
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
[jira] [Updated] (SOLR-2508) Master/Slave replication can leave
slave in inconsistent state of NullPointerException in solrHighligher.java
102
Posted by "Xing Li (JIRA)" <ji...@apache.org>.
[ 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 <init>
> 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,cumulative_inserts=15,cumulative_evictions=0,item_censorid={field=censorid,memSize=4755,tindexSize=0,time=30,phase1=30,nTerms=5,bigTerms=5,termInstances=0,uses=6350},item_genreid={field=genreid,memSize=16021464,tindexSize=41,time=101,phase1=93,nTerms=22,bigTerms=8,termInstances=946095,uses=6972},item_categoryid={field=categoryid,memSize=16042663,tindexSize=624,time=298,phase1=289,nTerms=6317,bigTerms=2,termInstances=3293460,uses=3410},item_pcategoryid={field=pcategoryid,memSize=16021287,tindexSize=41,time=33,phase1=24,nTerms=10,bigTerms=6,termInstances=202007,uses=3008},item_characterid={field=characterid,memSize=17435082,tindexSize=2755,time=1005,phase1=983,nTerms=27398,bigTerms=1,termInstances=4537318,uses=2899}}
> May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming result for Searcher@4f83f9df main
> fieldValueCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=62507,cumulative_hits=62464,cumulative_hitratio=0.99,cumulative_inserts=15,cumulative_evictions=0}
> May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming Searcher@4f83f9df main from Searcher@5f7808af main
> filterCache{lookups=164648,hits=163973,hitratio=0.99,inserts=6762,evictions=0,size=3337,warmupTime=1586,cumulative_lookups=455065,cumulative_hits=452914,cumulative_hitratio=0.99,cumulative_inserts=17617,cumulative_evictions=0}
> May 10, 2011 10:18:46 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_blogs] webapp=/solr path=/select params={sort=&indent=off&hl.fl=*&wt=json&hl=true&rows=50&start=0&facet.query=words:[0+TO+5]&facet.query=words:[6+TO+*]&facet.query=words:[11+TO+*]&facet.query=words:[31+TO+*]&facet.query=words:[51+TO+*]&facet.query=words:[151+TO+*]&facet.query=words:[301+TO+*]&q=%2Btext:video&q.op=and&facet.field=languageid&facet.field=genreid&facet.field=statusid&facet.field=censorid&fq=categoryid:4947&fq=characterid:56615&fq=characterid:23376} hits=22 status=0 QTime=3
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_users] webapp=/solr path=/select params={sort=&indent=off&start=0&q=%2Buname:regless*&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:47 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_blogs] webapp=/solr path=/select params={sort=&indent=off&hl.fl=*&wt=json&hl=true&rows=50&start=0&facet.query=words:[0+TO+5]&facet.query=words:[6+TO+*]&facet.query=words:[11+TO+*]&facet.query=words:[31+TO+*]&facet.query=words:[51+TO+*]&facet.query=words:[151+TO+*]&facet.query=words:[301+TO+*]&q=%2Btext:a&q.op=and&facet.field=languageid&facet.field=genreid&facet.field=statusid&facet.field=censorid&fq=categoryid:512&fq=genreid:3&fq=characterid:893&fq=characterid:891} hits=46 status=0 QTime=8
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_blogs] webapp=/solr path=/select params={sort=&indent=off&hl.fl=*&wt=json&hl=true&rows=50&start=0&facet.query=words:[0+TO+5]&facet.query=words:[6+TO+*]&facet.query=words:[11+TO+*]&facet.query=words:[31+TO+*]&facet.query=words:[51+TO+*]&facet.query=words:[151+TO+*]&facet.query=words:[301+TO+*]&q=%2Btext:oc&q.op=and&facet.field=pcategoryid&facet.field=categoryid&facet.field=genreid&facet.field=statusid&facet.field=censorid&fq=languageid:1} hits=87186 status=0 QTime=33
> May 10, 2011 10:18:47 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:47 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:47 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming result for Searcher@4f83f9df main
> filterCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=512,warmupTime=1715,cumulative_lookups=455141,cumulative_hits=452988,cumulative_hitratio=0.99,cumulative_inserts=17621,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming Searcher@4f83f9df main from Searcher@5f7808af main
> documentCache{lookups=395056,hits=235922,hitratio=0.59,inserts=159134,evictions=0,size=159134,warmupTime=0,cumulative_lookups=1081920,cumulative_hits=644938,cumulative_hitratio=0.59,cumulative_inserts=436982,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming result for Searcher@4f83f9df main
> documentCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=1081920,cumulative_hits=644938,cumulative_hitratio=0.59,cumulative_inserts=436982,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrCore registerSearcher
> INFO: [mysolr_blogs] Registered new searcher Searcher@4f83f9df main
> May 10, 2011 10:18:47 PM org.apache.solr.search.SolrIndexSearcher close
> INFO: Closing Searcher@5f7808af main
> fieldValueCache{lookups=22657,hits=22642,hitratio=0.99,inserts=5,evictions=0,size=5,warmupTime=0,cumulative_lookups=62515,cumulative_hits=62472,cumulative_hitratio=0.99,cumulative_inserts=15,cumulative_evictions=0,item_censorid={field=censorid,memSize=4755,tindexSize=0,time=30,phase1=30,nTerms=5,bigTerms=5,termInstances=0,uses=6353},item_genreid={field=genreid,memSize=16021464,tindexSize=41,time=101,phase1=93,nTerms=22,bigTerms=8,termInstances=946095,uses=6975},item_categoryid={field=categoryid,memSize=16042663,tindexSize=624,time=298,phase1=289,nTerms=6317,bigTerms=2,termInstances=3293460,uses=3411},item_pcategoryid={field=pcategoryid,memSize=16021287,tindexSize=41,time=33,phase1=24,nTerms=10,bigTerms=6,termInstances=202007,uses=3009},item_characterid={field=characterid,memSize=17435082,tindexSize=2755,time=1005,phase1=983,nTerms=27398,bigTerms=1,termInstances=4537318,uses=2899}}
> filterCache{lookups=164724,hits=164047,hitratio=0.99,inserts=6766,evictions=0,size=3339,warmupTime=1586,cumulative_lookups=455141,cumulative_hits=452988,cumulative_hitratio=0.99,cumulative_inserts=17621,cumulative_evictions=0}
> documentCache{lookups=395056,hits=235922,hitratio=0.59,inserts=159134,evictions=0,size=159134,warmupTime=0,cumulative_lookups=1081920,cumulative_hits=644938,cumulative_hitratio=0.59,cumulative_inserts=436982,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.handler.SnapPuller doCommit
> INFO: Force open index writer to make sure older index files get deleted
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrDeletionPolicy onInit
> INFO: SolrDeletionPolicy.onInit: commits:num=2
> commit{dir=/db/solr-master/multicore/mysolr_blogs/data/index,segFN=segments_j8,version=1302675975222,generation=692,filenames=[_va_0.tiv, _va_0.tib, _va_0.frq, _va.fnm, _va.fdt, _va_0.prx, segments_j8, _va.nrm, _va.fdx, 1.fnx]
> commit{dir=/db/solr-master/multicore/mysolr_blogs/data/index,segFN=segments_ja,version=1302675975227,generation=694,filenames=[_vc.nrm, _vc_0.prx, _vc_0.tib, segments_ja, _vc.fdx, _vc.fnm, _vc.fdt, _vc_0.frq, _vc_0.tiv, 1.fnx]
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrDeletionPolicy updateCommits
> INFO: newest commit = 1302675975227
> May 10, 2011 10:18:48 PM org.apache.solr.request.UnInvertedField <init>
> INFO: UnInverted multi-valued field {field=genreid,memSize=16021848,tindexSize=41,time=103,phase1=95,nTerms=22,bigTerms=8,termInstances=946118,uses=0}
> May 10, 2011 10:18:48 PM org.apache.solr.request.UnInvertedField <init>
> INFO: UnInverted multi-valued field {field=characterid,memSize=17435520,tindexSize=2751,time=409,phase1=389,nTerms=27399,bigTerms=1,termInstances=4537465,uses=0}
> May 10, 2011 10:18:48 PM org.apache.solr.request.UnInvertedField <init>
> INFO: UnInverted multi-valued field {field=censorid,memSize=4755,tindexSize=0,time=10,phase1=10,nTerms=5,bigTerms=5,termInstances=0,uses=0}
> May 10, 2011 10:18:48 PM org.apache.solr.common.SolrException log
> SEVERE: java.lang.NullPointerException
> at java.util.LinkedList$ListItr.next(Unknown Source)
> at org.apache.solr.highlight.SolrHighlighter.getHighlightFields(SolrHighlighter.java:102)
> at org.apache.solr.highlight.DefaultSolrHighlighter.doHighlighting(DefaultSolrHighlighter.java:347)
> at org.apache.solr.handler.component.HighlightComponent.process(HighlightComponent.java:121)
> at org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:231)
> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:129)
> at org.apache.solr.core.SolrCore.execute(SolrCore.java:1290)
> at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:353)
> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:248)
> at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1212)
> at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:399)
> at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
> at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
> at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
> at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:450)
> at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
> at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
> at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
> at org.mortbay.jetty.Server.handle(Server.java:326)
> at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
> at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:928)
> at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:549)
> at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
> at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
> at org.mortbay.jetty.bio.SocketConnector$Connection.run(SocketConnector.java:228)
> at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)
> May 10, 2011 10:18:48 PM org.apache.solr.common.SolrException log
> SEVERE: java.lang.NullPointerException
> at java.util.LinkedList$ListItr.next(Unknown Source)
> at org.apache.solr.highlight.SolrHighlighter.getHighlightFields(SolrHighlighter.java:102)
> at org.apache.solr.highlight.DefaultSolrHighlighter.doHighlighting(DefaultSolrHighlighter.java:347)
> at org.apache.solr.handler.component.HighlightComponent.process(HighlightComponent.java:121)
> at org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:231)
> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:129)
> at org.apache.solr.core.SolrCore.execute(SolrCore.java:1290)
> at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:353)
> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:248)
> at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1212)
> at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:399)
> at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
> at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
> at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
> at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:450)
> at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
> at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
> at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
> at org.mortbay.jetty.Server.handle(Server.java:326)
> at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
> at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:928)
> at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:549)
> at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
> at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
> at org.mortbay.jetty.bio.SocketConnector$Connection.run(SocketConnector.java:228)
> at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)
> {code}
> * After this point. "mysolr_blogs" will continue to throw 500 null errors on searches
--
This message is automatically generated by JIRA.
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
[jira] [Commented] (SOLR-2508) Master/Slave replication can leave
slave in inconsistent state of NullPointerException in solrHighligher.java
102
Posted by "Xing Li (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/SOLR-2508?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13031590#comment-13031590 ]
Xing Li commented on SOLR-2508:
-------------------------------
Got the problem more isolated.
The queries effected are those using "hl.fl=*" with "hl=true".
All queries run fine until something in the post replication triggers failures of NullPointerException in solrHighligher.java 102 when wildcard is used for highlighting field selection "hl.fl=*". Replacing those queries with a specific highlight field such as "hl.fl=uname" will then make the query work post "sudden failure".
> 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 <init>
> 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,cumulative_inserts=15,cumulative_evictions=0,item_censorid={field=censorid,memSize=4755,tindexSize=0,time=30,phase1=30,nTerms=5,bigTerms=5,termInstances=0,uses=6350},item_genreid={field=genreid,memSize=16021464,tindexSize=41,time=101,phase1=93,nTerms=22,bigTerms=8,termInstances=946095,uses=6972},item_categoryid={field=categoryid,memSize=16042663,tindexSize=624,time=298,phase1=289,nTerms=6317,bigTerms=2,termInstances=3293460,uses=3410},item_pcategoryid={field=pcategoryid,memSize=16021287,tindexSize=41,time=33,phase1=24,nTerms=10,bigTerms=6,termInstances=202007,uses=3008},item_characterid={field=characterid,memSize=17435082,tindexSize=2755,time=1005,phase1=983,nTerms=27398,bigTerms=1,termInstances=4537318,uses=2899}}
> May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming result for Searcher@4f83f9df main
> fieldValueCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=62507,cumulative_hits=62464,cumulative_hitratio=0.99,cumulative_inserts=15,cumulative_evictions=0}
> May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming Searcher@4f83f9df main from Searcher@5f7808af main
> filterCache{lookups=164648,hits=163973,hitratio=0.99,inserts=6762,evictions=0,size=3337,warmupTime=1586,cumulative_lookups=455065,cumulative_hits=452914,cumulative_hitratio=0.99,cumulative_inserts=17617,cumulative_evictions=0}
> May 10, 2011 10:18:46 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_blogs] webapp=/solr path=/select params={sort=&indent=off&hl.fl=*&wt=json&hl=true&rows=50&start=0&facet.query=words:[0+TO+5]&facet.query=words:[6+TO+*]&facet.query=words:[11+TO+*]&facet.query=words:[31+TO+*]&facet.query=words:[51+TO+*]&facet.query=words:[151+TO+*]&facet.query=words:[301+TO+*]&q=%2Btext:video&q.op=and&facet.field=languageid&facet.field=genreid&facet.field=statusid&facet.field=censorid&fq=categoryid:4947&fq=characterid:56615&fq=characterid:23376} hits=22 status=0 QTime=3
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_users] webapp=/solr path=/select params={sort=&indent=off&start=0&q=%2Buname:regless*&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:47 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_blogs] webapp=/solr path=/select params={sort=&indent=off&hl.fl=*&wt=json&hl=true&rows=50&start=0&facet.query=words:[0+TO+5]&facet.query=words:[6+TO+*]&facet.query=words:[11+TO+*]&facet.query=words:[31+TO+*]&facet.query=words:[51+TO+*]&facet.query=words:[151+TO+*]&facet.query=words:[301+TO+*]&q=%2Btext:a&q.op=and&facet.field=languageid&facet.field=genreid&facet.field=statusid&facet.field=censorid&fq=categoryid:512&fq=genreid:3&fq=characterid:893&fq=characterid:891} hits=46 status=0 QTime=8
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_blogs] webapp=/solr path=/select params={sort=&indent=off&hl.fl=*&wt=json&hl=true&rows=50&start=0&facet.query=words:[0+TO+5]&facet.query=words:[6+TO+*]&facet.query=words:[11+TO+*]&facet.query=words:[31+TO+*]&facet.query=words:[51+TO+*]&facet.query=words:[151+TO+*]&facet.query=words:[301+TO+*]&q=%2Btext:oc&q.op=and&facet.field=pcategoryid&facet.field=categoryid&facet.field=genreid&facet.field=statusid&facet.field=censorid&fq=languageid:1} hits=87186 status=0 QTime=33
> May 10, 2011 10:18:47 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:47 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:47 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming result for Searcher@4f83f9df main
> filterCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=512,warmupTime=1715,cumulative_lookups=455141,cumulative_hits=452988,cumulative_hitratio=0.99,cumulative_inserts=17621,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming Searcher@4f83f9df main from Searcher@5f7808af main
> documentCache{lookups=395056,hits=235922,hitratio=0.59,inserts=159134,evictions=0,size=159134,warmupTime=0,cumulative_lookups=1081920,cumulative_hits=644938,cumulative_hitratio=0.59,cumulative_inserts=436982,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming result for Searcher@4f83f9df main
> documentCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=1081920,cumulative_hits=644938,cumulative_hitratio=0.59,cumulative_inserts=436982,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrCore registerSearcher
> INFO: [mysolr_blogs] Registered new searcher Searcher@4f83f9df main
> May 10, 2011 10:18:47 PM org.apache.solr.search.SolrIndexSearcher close
> INFO: Closing Searcher@5f7808af main
> fieldValueCache{lookups=22657,hits=22642,hitratio=0.99,inserts=5,evictions=0,size=5,warmupTime=0,cumulative_lookups=62515,cumulative_hits=62472,cumulative_hitratio=0.99,cumulative_inserts=15,cumulative_evictions=0,item_censorid={field=censorid,memSize=4755,tindexSize=0,time=30,phase1=30,nTerms=5,bigTerms=5,termInstances=0,uses=6353},item_genreid={field=genreid,memSize=16021464,tindexSize=41,time=101,phase1=93,nTerms=22,bigTerms=8,termInstances=946095,uses=6975},item_categoryid={field=categoryid,memSize=16042663,tindexSize=624,time=298,phase1=289,nTerms=6317,bigTerms=2,termInstances=3293460,uses=3411},item_pcategoryid={field=pcategoryid,memSize=16021287,tindexSize=41,time=33,phase1=24,nTerms=10,bigTerms=6,termInstances=202007,uses=3009},item_characterid={field=characterid,memSize=17435082,tindexSize=2755,time=1005,phase1=983,nTerms=27398,bigTerms=1,termInstances=4537318,uses=2899}}
> filterCache{lookups=164724,hits=164047,hitratio=0.99,inserts=6766,evictions=0,size=3339,warmupTime=1586,cumulative_lookups=455141,cumulative_hits=452988,cumulative_hitratio=0.99,cumulative_inserts=17621,cumulative_evictions=0}
> documentCache{lookups=395056,hits=235922,hitratio=0.59,inserts=159134,evictions=0,size=159134,warmupTime=0,cumulative_lookups=1081920,cumulative_hits=644938,cumulative_hitratio=0.59,cumulative_inserts=436982,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.handler.SnapPuller doCommit
> INFO: Force open index writer to make sure older index files get deleted
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrDeletionPolicy onInit
> INFO: SolrDeletionPolicy.onInit: commits:num=2
> commit{dir=/db/solr-master/multicore/mysolr_blogs/data/index,segFN=segments_j8,version=1302675975222,generation=692,filenames=[_va_0.tiv, _va_0.tib, _va_0.frq, _va.fnm, _va.fdt, _va_0.prx, segments_j8, _va.nrm, _va.fdx, 1.fnx]
> commit{dir=/db/solr-master/multicore/mysolr_blogs/data/index,segFN=segments_ja,version=1302675975227,generation=694,filenames=[_vc.nrm, _vc_0.prx, _vc_0.tib, segments_ja, _vc.fdx, _vc.fnm, _vc.fdt, _vc_0.frq, _vc_0.tiv, 1.fnx]
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrDeletionPolicy updateCommits
> INFO: newest commit = 1302675975227
> May 10, 2011 10:18:48 PM org.apache.solr.request.UnInvertedField <init>
> INFO: UnInverted multi-valued field {field=genreid,memSize=16021848,tindexSize=41,time=103,phase1=95,nTerms=22,bigTerms=8,termInstances=946118,uses=0}
> May 10, 2011 10:18:48 PM org.apache.solr.request.UnInvertedField <init>
> INFO: UnInverted multi-valued field {field=characterid,memSize=17435520,tindexSize=2751,time=409,phase1=389,nTerms=27399,bigTerms=1,termInstances=4537465,uses=0}
> May 10, 2011 10:18:48 PM org.apache.solr.request.UnInvertedField <init>
> INFO: UnInverted multi-valued field {field=censorid,memSize=4755,tindexSize=0,time=10,phase1=10,nTerms=5,bigTerms=5,termInstances=0,uses=0}
> May 10, 2011 10:18:48 PM org.apache.solr.common.SolrException log
> SEVERE: java.lang.NullPointerException
> at java.util.LinkedList$ListItr.next(Unknown Source)
> at org.apache.solr.highlight.SolrHighlighter.getHighlightFields(SolrHighlighter.java:102)
> at org.apache.solr.highlight.DefaultSolrHighlighter.doHighlighting(DefaultSolrHighlighter.java:347)
> at org.apache.solr.handler.component.HighlightComponent.process(HighlightComponent.java:121)
> at org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:231)
> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:129)
> at org.apache.solr.core.SolrCore.execute(SolrCore.java:1290)
> at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:353)
> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:248)
> at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1212)
> at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:399)
> at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
> at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
> at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
> at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:450)
> at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
> at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
> at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
> at org.mortbay.jetty.Server.handle(Server.java:326)
> at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
> at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:928)
> at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:549)
> at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
> at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
> at org.mortbay.jetty.bio.SocketConnector$Connection.run(SocketConnector.java:228)
> at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)
> May 10, 2011 10:18:48 PM org.apache.solr.common.SolrException log
> SEVERE: java.lang.NullPointerException
> at java.util.LinkedList$ListItr.next(Unknown Source)
> at org.apache.solr.highlight.SolrHighlighter.getHighlightFields(SolrHighlighter.java:102)
> at org.apache.solr.highlight.DefaultSolrHighlighter.doHighlighting(DefaultSolrHighlighter.java:347)
> at org.apache.solr.handler.component.HighlightComponent.process(HighlightComponent.java:121)
> at org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:231)
> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:129)
> at org.apache.solr.core.SolrCore.execute(SolrCore.java:1290)
> at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:353)
> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:248)
> at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1212)
> at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:399)
> at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
> at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
> at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
> at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:450)
> at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
> at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
> at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
> at org.mortbay.jetty.Server.handle(Server.java:326)
> at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
> at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:928)
> at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:549)
> at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
> at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
> at org.mortbay.jetty.bio.SocketConnector$Connection.run(SocketConnector.java:228)
> at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)
> {code}
> * After this point. "mysolr_blogs" will continue to throw 500 null errors on searches
--
This message is automatically generated by JIRA.
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
[jira] [Updated] (SOLR-2508) Master/Slave replication can leave
slave in inconsistent state of NullPointerException in solrHighligher.java
102
Posted by "Xing Li (JIRA)" <ji...@apache.org>.
[ 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 <init>
> 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,cumulative_inserts=15,cumulative_evictions=0,item_censorid={field=censorid,memSize=4755,tindexSize=0,time=30,phase1=30,nTerms=5,bigTerms=5,termInstances=0,uses=6350},item_genreid={field=genreid,memSize=16021464,tindexSize=41,time=101,phase1=93,nTerms=22,bigTerms=8,termInstances=946095,uses=6972},item_categoryid={field=categoryid,memSize=16042663,tindexSize=624,time=298,phase1=289,nTerms=6317,bigTerms=2,termInstances=3293460,uses=3410},item_pcategoryid={field=pcategoryid,memSize=16021287,tindexSize=41,time=33,phase1=24,nTerms=10,bigTerms=6,termInstances=202007,uses=3008},item_characterid={field=characterid,memSize=17435082,tindexSize=2755,time=1005,phase1=983,nTerms=27398,bigTerms=1,termInstances=4537318,uses=2899}}
> May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming result for Searcher@4f83f9df main
> fieldValueCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=62507,cumulative_hits=62464,cumulative_hitratio=0.99,cumulative_inserts=15,cumulative_evictions=0}
> May 10, 2011 10:18:46 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming Searcher@4f83f9df main from Searcher@5f7808af main
> filterCache{lookups=164648,hits=163973,hitratio=0.99,inserts=6762,evictions=0,size=3337,warmupTime=1586,cumulative_lookups=455065,cumulative_hits=452914,cumulative_hitratio=0.99,cumulative_inserts=17617,cumulative_evictions=0}
> May 10, 2011 10:18:46 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_blogs] webapp=/solr path=/select params={sort=&indent=off&hl.fl=*&wt=json&hl=true&rows=50&start=0&facet.query=words:[0+TO+5]&facet.query=words:[6+TO+*]&facet.query=words:[11+TO+*]&facet.query=words:[31+TO+*]&facet.query=words:[51+TO+*]&facet.query=words:[151+TO+*]&facet.query=words:[301+TO+*]&q=%2Btext:video&q.op=and&facet.field=languageid&facet.field=genreid&facet.field=statusid&facet.field=censorid&fq=categoryid:4947&fq=characterid:56615&fq=characterid:23376} hits=22 status=0 QTime=3
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_users] webapp=/solr path=/select params={sort=&indent=off&start=0&q=%2Buname:regless*&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:47 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_blogs] webapp=/solr path=/select params={sort=&indent=off&hl.fl=*&wt=json&hl=true&rows=50&start=0&facet.query=words:[0+TO+5]&facet.query=words:[6+TO+*]&facet.query=words:[11+TO+*]&facet.query=words:[31+TO+*]&facet.query=words:[51+TO+*]&facet.query=words:[151+TO+*]&facet.query=words:[301+TO+*]&q=%2Btext:a&q.op=and&facet.field=languageid&facet.field=genreid&facet.field=statusid&facet.field=censorid&fq=categoryid:512&fq=genreid:3&fq=characterid:893&fq=characterid:891} hits=46 status=0 QTime=8
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrCore execute
> INFO: [mysolr_blogs] webapp=/solr path=/select params={sort=&indent=off&hl.fl=*&wt=json&hl=true&rows=50&start=0&facet.query=words:[0+TO+5]&facet.query=words:[6+TO+*]&facet.query=words:[11+TO+*]&facet.query=words:[31+TO+*]&facet.query=words:[51+TO+*]&facet.query=words:[151+TO+*]&facet.query=words:[301+TO+*]&q=%2Btext:oc&q.op=and&facet.field=pcategoryid&facet.field=categoryid&facet.field=genreid&facet.field=statusid&facet.field=censorid&fq=languageid:1} hits=87186 status=0 QTime=33
> May 10, 2011 10:18:47 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:47 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:47 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming result for Searcher@4f83f9df main
> filterCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=512,warmupTime=1715,cumulative_lookups=455141,cumulative_hits=452988,cumulative_hitratio=0.99,cumulative_inserts=17621,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming Searcher@4f83f9df main from Searcher@5f7808af main
> documentCache{lookups=395056,hits=235922,hitratio=0.59,inserts=159134,evictions=0,size=159134,warmupTime=0,cumulative_lookups=1081920,cumulative_hits=644938,cumulative_hitratio=0.59,cumulative_inserts=436982,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.search.SolrIndexSearcher warm
> INFO: autowarming result for Searcher@4f83f9df main
> documentCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=1081920,cumulative_hits=644938,cumulative_hitratio=0.59,cumulative_inserts=436982,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrCore registerSearcher
> INFO: [mysolr_blogs] Registered new searcher Searcher@4f83f9df main
> May 10, 2011 10:18:47 PM org.apache.solr.search.SolrIndexSearcher close
> INFO: Closing Searcher@5f7808af main
> fieldValueCache{lookups=22657,hits=22642,hitratio=0.99,inserts=5,evictions=0,size=5,warmupTime=0,cumulative_lookups=62515,cumulative_hits=62472,cumulative_hitratio=0.99,cumulative_inserts=15,cumulative_evictions=0,item_censorid={field=censorid,memSize=4755,tindexSize=0,time=30,phase1=30,nTerms=5,bigTerms=5,termInstances=0,uses=6353},item_genreid={field=genreid,memSize=16021464,tindexSize=41,time=101,phase1=93,nTerms=22,bigTerms=8,termInstances=946095,uses=6975},item_categoryid={field=categoryid,memSize=16042663,tindexSize=624,time=298,phase1=289,nTerms=6317,bigTerms=2,termInstances=3293460,uses=3411},item_pcategoryid={field=pcategoryid,memSize=16021287,tindexSize=41,time=33,phase1=24,nTerms=10,bigTerms=6,termInstances=202007,uses=3009},item_characterid={field=characterid,memSize=17435082,tindexSize=2755,time=1005,phase1=983,nTerms=27398,bigTerms=1,termInstances=4537318,uses=2899}}
> filterCache{lookups=164724,hits=164047,hitratio=0.99,inserts=6766,evictions=0,size=3339,warmupTime=1586,cumulative_lookups=455141,cumulative_hits=452988,cumulative_hitratio=0.99,cumulative_inserts=17621,cumulative_evictions=0}
> documentCache{lookups=395056,hits=235922,hitratio=0.59,inserts=159134,evictions=0,size=159134,warmupTime=0,cumulative_lookups=1081920,cumulative_hits=644938,cumulative_hitratio=0.59,cumulative_inserts=436982,cumulative_evictions=0}
> May 10, 2011 10:18:47 PM org.apache.solr.handler.SnapPuller doCommit
> INFO: Force open index writer to make sure older index files get deleted
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrDeletionPolicy onInit
> INFO: SolrDeletionPolicy.onInit: commits:num=2
> commit{dir=/db/solr-master/multicore/mysolr_blogs/data/index,segFN=segments_j8,version=1302675975222,generation=692,filenames=[_va_0.tiv, _va_0.tib, _va_0.frq, _va.fnm, _va.fdt, _va_0.prx, segments_j8, _va.nrm, _va.fdx, 1.fnx]
> commit{dir=/db/solr-master/multicore/mysolr_blogs/data/index,segFN=segments_ja,version=1302675975227,generation=694,filenames=[_vc.nrm, _vc_0.prx, _vc_0.tib, segments_ja, _vc.fdx, _vc.fnm, _vc.fdt, _vc_0.frq, _vc_0.tiv, 1.fnx]
> May 10, 2011 10:18:47 PM org.apache.solr.core.SolrDeletionPolicy updateCommits
> INFO: newest commit = 1302675975227
> May 10, 2011 10:18:48 PM org.apache.solr.request.UnInvertedField <init>
> INFO: UnInverted multi-valued field {field=genreid,memSize=16021848,tindexSize=41,time=103,phase1=95,nTerms=22,bigTerms=8,termInstances=946118,uses=0}
> May 10, 2011 10:18:48 PM org.apache.solr.request.UnInvertedField <init>
> INFO: UnInverted multi-valued field {field=characterid,memSize=17435520,tindexSize=2751,time=409,phase1=389,nTerms=27399,bigTerms=1,termInstances=4537465,uses=0}
> May 10, 2011 10:18:48 PM org.apache.solr.request.UnInvertedField <init>
> INFO: UnInverted multi-valued field {field=censorid,memSize=4755,tindexSize=0,time=10,phase1=10,nTerms=5,bigTerms=5,termInstances=0,uses=0}
> May 10, 2011 10:18:48 PM org.apache.solr.common.SolrException log
> SEVERE: java.lang.NullPointerException
> at java.util.LinkedList$ListItr.next(Unknown Source)
> at org.apache.solr.highlight.SolrHighlighter.getHighlightFields(SolrHighlighter.java:102)
> at org.apache.solr.highlight.DefaultSolrHighlighter.doHighlighting(DefaultSolrHighlighter.java:347)
> at org.apache.solr.handler.component.HighlightComponent.process(HighlightComponent.java:121)
> at org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:231)
> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:129)
> at org.apache.solr.core.SolrCore.execute(SolrCore.java:1290)
> at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:353)
> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:248)
> at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1212)
> at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:399)
> at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
> at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
> at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
> at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:450)
> at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
> at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
> at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
> at org.mortbay.jetty.Server.handle(Server.java:326)
> at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
> at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:928)
> at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:549)
> at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
> at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
> at org.mortbay.jetty.bio.SocketConnector$Connection.run(SocketConnector.java:228)
> at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)
> May 10, 2011 10:18:48 PM org.apache.solr.common.SolrException log
> SEVERE: java.lang.NullPointerException
> at java.util.LinkedList$ListItr.next(Unknown Source)
> at org.apache.solr.highlight.SolrHighlighter.getHighlightFields(SolrHighlighter.java:102)
> at org.apache.solr.highlight.DefaultSolrHighlighter.doHighlighting(DefaultSolrHighlighter.java:347)
> at org.apache.solr.handler.component.HighlightComponent.process(HighlightComponent.java:121)
> at org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:231)
> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:129)
> at org.apache.solr.core.SolrCore.execute(SolrCore.java:1290)
> at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:353)
> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:248)
> at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1212)
> at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:399)
> at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
> at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
> at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
> at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:450)
> at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
> at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
> at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
> at org.mortbay.jetty.Server.handle(Server.java:326)
> at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
> at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:928)
> at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:549)
> at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
> at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
> at org.mortbay.jetty.bio.SocketConnector$Connection.run(SocketConnector.java:228)
> at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)
> {code}
> * After this point. "mysolr_blogs" will continue to throw 500 null errors on searches
--
This message is automatically generated by JIRA.
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