Thanks for the input!
Erick - To clarify, we see the No Uncommitted Changes message repeatedly
for a number of commits (not a consistent number each time this happens)
and then eventually we see a commit that successfully finds changes, at
which point the documents are available.
Shalin - That bug looks like it could be related to our case, did you
notice any impact of the bug in situations where there were not just
pending deletes by term? In our case, we are adding documents, we do have
some deletes, but the bulk are adds. We can see the logging of the adds in
the solr log prior to seeing the No Uncommitted Changes message.
Either way, it may be useful for us to upgrade and see if it fixes the
issue. I'll let you know if that works out once we get a chance to do that.
Thanks,
Justin
On Mon, Jun 9, 2014 at 3:02 AM, Shalin Shekhar Mangar <
shalinman...@gmail.com> wrote:
> I think this may be the same bug as LUCENE-5289 which was fixed in 4.5.1.
> Can you upgrade to 4.5.1 and see if that solves the problem?
>
>
>
>
> On Fri, Jun 6, 2014 at 7:17 PM, Justin Sweeney <justin.sweene...@gmail.com
> >
> wrote:
>
> > Hi,
> >
> > An application I am working on indexes documents to a Solr index. This
> Solr
> > index is setup as a single node, without any replication. This index is
> > running Solr 4.5.0.
> >
> > We have noticed an issue lately that is causing some problems for our
> > application. The problem is that we add/update a number of documents in
> the
> > Solr index and we have the index setup to autoCommit (hard) once every 30
> > minutes. In the Solr logs, I am able to see the add command to Solr and I
> > can also see Solr start the hard commit. When this hard commit occurs, we
> > see the following message:
> > INFO - 2014-06-04 20:13:55.135;
> > org.apache.solr.update.DirectUpdateHandler2; No uncommitted changes.
> > Skipping IW.commit.
> >
> > This only happens sometimes, but Solr will go hours (we have seen 6-12
> > hours of this behavior) before it does a hard commit where it find
> changes.
> > After the hard commit where the changes are found, we are then able to
> > search for and find the documents that were added hours ago, but up until
> > that point the documents are not searchable.
> >
> > We tried enabling autoSoftCommit every 5 minutes in the hope that this
> > would help, but we are seeing the same behavior.
> >
> > Here is a sampling of the logs showing this occurring (I've trimmed it
> down
> > to just show what is happening):
> >
> > INFO - 2014-06-05 20:00:41.300;
> > >> org.apache.solr.update.processor.LogUpdateProcessor; [zoomCollection]
> > >> webapp=/solr path=/update params={wt=javabin&version=2}
> > {add=[359453225]} 0
> > >> 0
> > >
> > > INFO - 2014-06-05 20:00:41.376;
> > >> org.apache.solr.update.processor.LogUpdateProcessor; [zoomCollection]
> > >> webapp=/solr path=/update params={wt=javabin&version=2}
> > {add=[347170717]} 0
> > >> 1
> > >
> > > INFO - 2014-06-05 20:00:51.527;
> > >> org.apache.solr.update.DirectUpdateHandler2; start
> > >>
> >
> commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
> > >
> > > INFO - 2014-06-05 20:00:51.533;
> > org.apache.solr.search.SolrIndexSearcher;
> > >> Opening Searcher@257c43d main
> > >
> > > INFO - 2014-06-05 20:00:51.533;
> > >> org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
> > >
> > > INFO - 2014-06-05 20:00:51.545;
> > org.apache.solr.core.QuerySenderListener;
> > >> QuerySenderListener sending requests to Searcher@257c43d
> > >> main{StandardDirectoryReader(segments_acl:1367002775953
> > >> _2f28(4.5):C13583563/4081507 _2gl6(4.5):C2754573/193533
> > >> _2g21(4.5):C1046256/296354 _2ge2(4.5):C835858/206139
> > >> _2gqd(4.5):C383500/31051 _2gmu(4.5):C125197/32491
> _2grl(4.5):C46906/1255
> > >> _2gpj(4.5):C66480/16562 _2gra(4.5):C364/22 _2gr1(4.5):C36064/2556
> > >> _2gqg(4.5):C42504/21515 _2gqm(4.5):C26821/12659
> _2gqu(4.5):C24172/10240
> > >> _2gqy(4.5):C697/215 _2gr2(4.5):C878/352 _2gr7(4.5):C28135/11775
> > >> _2gr9(4.5):C3276/1341 _2grb(4.5):C5/1 _2grc(4.5):C3247/1219
> > _2grd(4.5):C6/1
> > >> _2grf(4.5):C5/2 _2grg(4.5):C23659/10967 _2grh(4.5):C1 _2grj(4.5):C1
> > >> _2grk(4.5):C5160/1482 _2grm(4.5):C1210/351 _2grn(4.5):C3957/1372
> > >> _2gro(4.5):C7734/2207 _2grp(4.5):C220/36)}
> > >
> > > INFO - 2014-06-05 20:00:51.546; org.apache.solr.core.SolrCore;
> > >> [zoomCollection] webapp=null path=null
> > >> params={event=newSearcher&q=d_name:ibm&distrib=false} hits=38 status=0
> > >> QTime=0
> > >
> > > INFO - 2014-06-05 20:00:51.546;
> > org.apache.solr.core.QuerySenderListener;
> > >> QuerySenderListener done.
> > >
> > > INFO - 2014-06-05 20:00:51.547; org.apache.solr.core.SolrCore;
> > >> [zoomCollection] Registered new searcher Searcher@257c43d
> > >> main{StandardDirectoryReader(segments_acl:1367002775953
> > >> _2f28(4.5):C13583563/4081507 _2gl6(4.5):C2754573/193533
> > >> _2g21(4.5):C1046256/296354 _2ge2(4.5):C835858/206139
> > >> _2gqd(4.5):C383500/31051 _2gmu(4.5):C125197/32491
> _2grl(4.5):C46906/1255
> > >> _2gpj(4.5):C66480/16562 _2gra(4.5):C364/22 _2gr1(4.5):C36064/2556
> > >> _2gqg(4.5):C42504/21515 _2gqm(4.5):C26821/12659
> _2gqu(4.5):C24172/10240
> > >> _2gqy(4.5):C697/215 _2gr2(4.5):C878/352 _2gr7(4.5):C28135/11775
> > >> _2gr9(4.5):C3276/1341 _2grb(4.5):C5/1 _2grc(4.5):C3247/1219
> > _2grd(4.5):C6/1
> > >> _2grf(4.5):C5/2 _2grg(4.5):C23659/10967 _2grh(4.5):C1 _2grj(4.5):C1
> > >> _2grk(4.5):C5160/1482 _2grm(4.5):C1210/351 _2grn(4.5):C3957/1372
> > >> _2gro(4.5):C7734/2207 _2grp(4.5):C220/36)}
> > >
> > > INFO - 2014-06-05 20:01:10.557;
> > >> org.apache.solr.update.DirectUpdateHandler2; start
> > >>
> >
> commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
> > >
> > > INFO - 2014-06-05 20:01:10.559; org.apache.solr.core.SolrCore;
> > >> [zoomCollection] webapp=/solr path=/select
> > >>
> >
> params={fl=d_ticker,d_location,d_id,d_source_count,d_xml_domain,d_cik,d_keyword_count,d_xml_name,d_xml_contact,d_main_domain,d_location_code&start=0&q=d_domain:("
> > >> www.northwestcollege.edu")&wt=javabin&version=2&rows=999999} hits=4
> > >> status=0 QTime=40
> > >
> > > INFO - 2014-06-05 20:01:10.563;
> > org.apache.solr.search.SolrIndexSearcher;
> > >> Opening Searcher@69f90ad1 main
> > >
> > > INFO - 2014-06-05 20:01:10.564;
> > >> org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
> > >
> > > INFO - 2014-06-05 20:01:10.579;
> > org.apache.solr.core.QuerySenderListener;
> > >> QuerySenderListener sending requests to Searcher@69f90ad1
> > >> main{StandardDirectoryReader(segments_acl:1367002775953
> > >> _2f28(4.5):C13583563/4081507 _2gl6(4.5):C2754573/193533
> > >> _2g21(4.5):C1046256/296354 _2ge2(4.5):C835858/206139
> > >> _2gqd(4.5):C383500/31051 _2gmu(4.5):C125197/32491
> _2grl(4.5):C46906/1255
> > >> _2gpj(4.5):C66480/16562 _2gra(4.5):C364/22 _2gr1(4.5):C36064/2556
> > >> _2gqg(4.5):C42504/21515 _2gqm(4.5):C26821/12659
> _2gqu(4.5):C24172/10240
> > >> _2gqy(4.5):C697/215 _2gr2(4.5):C878/352 _2gr7(4.5):C28135/11775
> > >> _2gr9(4.5):C3276/1341 _2grb(4.5):C5/1 _2grc(4.5):C3247/1219
> > _2grd(4.5):C6/1
> > >> _2grf(4.5):C5/2 _2grg(4.5):C23659/10967 _2grh(4.5):C1 _2grj(4.5):C1
> > >> _2grk(4.5):C5160/1482 _2grm(4.5):C1210/351 _2grn(4.5):C3957/1372
> > >> _2gro(4.5):C7734/2207 _2grp(4.5):C220/36)}
> > >
> > > INFO - 2014-06-05 20:01:10.580; org.apache.solr.core.SolrCore;
> > >> [zoomCollection] webapp=null path=null
> > >> params={event=newSearcher&q=d_name:ibm&distrib=false} hits=38 status=0
> > >> QTime=1
> > >
> > > INFO - 2014-06-05 20:01:10.580;
> > org.apache.solr.core.QuerySenderListener;
> > >> QuerySenderListener done.
> > >
> > > INFO - 2014-06-05 20:01:10.580; org.apache.solr.core.SolrCore;
> > >> [zoomCollection] Registered new searcher Searcher@69f90ad1
> > >> main{StandardDirectoryReader(segments_acl:1367002775953
> > >> _2f28(4.5):C13583563/4081507 _2gl6(4.5):C2754573/193533
> > >> _2g21(4.5):C1046256/296354 _2ge2(4.5):C835858/206139
> > >> _2gqd(4.5):C383500/31051 _2gmu(4.5):C125197/32491
> _2grl(4.5):C46906/1255
> > >> _2gpj(4.5):C66480/16562 _2gra(4.5):C364/22 _2gr1(4.5):C36064/2556
> > >> _2gqg(4.5):C42504/21515 _2gqm(4.5):C26821/12659
> _2gqu(4.5):C24172/10240
> > >> _2gqy(4.5):C697/215 _2gr2(4.5):C878/352 _2gr7(4.5):C28135/11775
> > >> _2gr9(4.5):C3276/1341 _2grb(4.5):C5/1 _2grc(4.5):C3247/1219
> > _2grd(4.5):C6/1
> > >> _2grf(4.5):C5/2 _2grg(4.5):C23659/10967 _2grh(4.5):C1 _2grj(4.5):C1
> > >> _2grk(4.5):C5160/1482 _2grm(4.5):C1210/351 _2grn(4.5):C3957/1372
> > >> _2gro(4.5):C7734/2207 _2grp(4.5):C220/36)}
> > >
> > > INFO - 2014-06-05 20:14:25.707;
> > >> org.apache.solr.update.DirectUpdateHandler2; start
> > >>
> >
> commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
> > >
> > > INFO - 2014-06-05 20:14:25.708;
> > >> org.apache.solr.update.DirectUpdateHandler2; No uncommitted changes.
> > >> Skipping IW.commit.
> > >
> > > INFO - 2014-06-05 20:14:25.714;
> > org.apache.solr.search.SolrIndexSearcher;
> > >> Opening Searcher@4010a5b9 main
> > >
> > > INFO - 2014-06-05 20:14:25.714;
> > >> org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
> > >
> > > INFO - 2014-06-05 20:14:25.725;
> > org.apache.solr.core.QuerySenderListener;
> > >> QuerySenderListener sending requests to Searcher@4010a5b9
> > >> main{StandardDirectoryReader(segments_acl:1367002775953
> > >> _2f28(4.5):C13583563/4081507 _2gl6(4.5):C2754573/193533
> > >> _2g21(4.5):C1046256/296354 _2ge2(4.5):C835858/206139
> > >> _2gqd(4.5):C383500/31051 _2gmu(4.5):C125197/32491
> _2grl(4.5):C46906/1255
> > >> _2gpj(4.5):C66480/16562 _2gra(4.5):C364/22 _2gr1(4.5):C36064/2556
> > >> _2gqg(4.5):C42504/21515 _2gqm(4.5):C26821/12659
> _2gqu(4.5):C24172/10240
> > >> _2gqy(4.5):C697/215 _2gr2(4.5):C878/352 _2gr7(4.5):C28135/11775
> > >> _2gr9(4.5):C3276/1341 _2grb(4.5):C5/1 _2grc(4.5):C3247/1219
> > _2grd(4.5):C6/1
> > >> _2grf(4.5):C5/2 _2grg(4.5):C23659/10967 _2grh(4.5):C1 _2grj(4.5):C1
> > >> _2grk(4.5):C5160/1482 _2grm(4.5):C1210/351 _2grn(4.5):C3957/1372
> > >> _2gro(4.5):C7734/2207 _2grp(4.5):C220/36)}
> > >
> > > INFO - 2014-06-05 20:14:25.725; org.apache.solr.core.SolrCore;
> > >> [zoomCollection] webapp=null path=null
> > >> params={event=newSearcher&q=d_name:ibm&distrib=false} hits=38 status=0
> > >> QTime=0
> > >
> > > INFO - 2014-06-05 20:14:25.726;
> > org.apache.solr.core.QuerySenderListener;
> > >> QuerySenderListener done.
> > >
> > > INFO - 2014-06-05 20:14:25.726; org.apache.solr.core.SolrCore;
> > >> [zoomCollection] Registered new searcher Searcher@4010a5b9
> > >> main{StandardDirectoryReader(segments_acl:1367002775953
> > >> _2f28(4.5):C13583563/4081507 _2gl6(4.5):C2754573/193533
> > >> _2g21(4.5):C1046256/296354 _2ge2(4.5):C835858/206139
> > >> _2gqd(4.5):C383500/31051 _2gmu(4.5):C125197/32491
> _2grl(4.5):C46906/1255
> > >> _2gpj(4.5):C66480/16562 _2gra(4.5):C364/22 _2gr1(4.5):C36064/2556
> > >> _2gqg(4.5):C42504/21515 _2gqm(4.5):C26821/12659
> _2gqu(4.5):C24172/10240
> > >> _2gqy(4.5):C697/215 _2gr2(4.5):C878/352 _2gr7(4.5):C28135/11775
> > >> _2gr9(4.5):C3276/1341 _2grb(4.5):C5/1 _2grc(4.5):C3247/1219
> > _2grd(4.5):C6/1
> > >> _2grf(4.5):C5/2 _2grg(4.5):C23659/10967 _2grh(4.5):C1 _2grj(4.5):C1
> > >> _2grk(4.5):C5160/1482 _2grm(4.5):C1210/351 _2grn(4.5):C3957/1372
> > >> _2gro(4.5):C7734/2207 _2grp(4.5):C220/36)}
> > >
> > > INFO - 2014-06-05 21:14:26.949;
> > >> org.apache.solr.update.DirectUpdateHandler2; start
> > >>
> >
> commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
> > >
> > > INFO - 2014-06-05 21:14:36.727;
> org.apache.solr.core.SolrDeletionPolicy;
> > >> SolrDeletionPolicy.onCommit: commits: num=2
> > >
> > >
> > >> commit{dir=NRTCachingDirectory(org.apache.lucene.store.MMapDirectory@
> > /data/solr-data/index
> > >> lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@26041cb3
> ;
> > >> maxCacheMB=48.0
> maxMergeSizeMB=4.0),segFN=segments_acl,generation=13413}
> > >
> > >
> > >> commit{dir=NRTCachingDirectory(org.apache.lucene.store.MMapDirectory@
> > /data/solr-data/index
> > >> lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@26041cb3
> ;
> > >> maxCacheMB=48.0
> maxMergeSizeMB=4.0),segFN=segments_acm,generation=13414}
> > >
> > > INFO - 2014-06-05 21:14:36.728;
> org.apache.solr.core.SolrDeletionPolicy;
> > >> newest commit generation = 13414
> > >
> > > INFO - 2014-06-05 21:14:36.749;
> > org.apache.solr.search.SolrIndexSearcher;
> > >> Opening Searcher@5bf20a8a main
> > >
> > > INFO - 2014-06-05 21:14:36.750;
> > >> org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
> > >
> > > INFO - 2014-06-05 21:14:36.759;
> > org.apache.solr.core.QuerySenderListener;
> > >> QuerySenderListener sending requests to Searcher@5bf20a8a
> > >> main{StandardDirectoryReader(segments_acm:1367002775958
> > >> _2f28(4.5):C13583563/4088615 _2gl6(4.5):C2754573/202192
> > >> _2g21(4.5):C1046256/298243 _2ge2(4.5):C835858/208834
> > >> _2gqd(4.5):C383500/35732 _2gmu(4.5):C125197/33714
> _2grl(4.5):C46906/3282
> > >> _2gpj(4.5):C66480/17459 _2gra(4.5):C364/40 _2gr1(4.5):C36064/3442
> > >> _2gqg(4.5):C42504/22410 _2gqm(4.5):C26821/13787
> _2gqu(4.5):C24172/10804
> > >> _2gqy(4.5):C697/231 _2gr2(4.5):C878/382 _2gr7(4.5):C28135/12761
> > >> _2gr9(4.5):C3276/1478 _2grb(4.5):C5/1 _2grc(4.5):C3247/1323
> > _2grd(4.5):C6/1
> > >> _2grf(4.5):C5/2 _2grg(4.5):C23659/11895 _2grh(4.5):C1 _2grj(4.5):C1
> > >> _2grk(4.5):C5160/1982 _2grm(4.5):C1210/531 _2grn(4.5):C3957/1790
> > >> _2gro(4.5):C7734/3504 _2grp(4.5):C220/106 _2grq(4.5):C72751/30166
> > >> _2grr(4.5):C1)}
> > >
> > > INFO - 2014-06-05 21:14:36.759; org.apache.solr.core.SolrCore;
> > >> [zoomCollection] webapp=null path=null
> > >> params={event=newSearcher&q=d_name:ibm&distrib=false} hits=38 status=0
> > >> QTime=0
> > >
> > > INFO - 2014-06-05 21:14:36.760;
> > org.apache.solr.core.QuerySenderListener;
> > >> QuerySenderListener done.
> > >
> > > INFO - 2014-06-05 21:14:36.760; org.apache.solr.core.SolrCore;
> > >> [zoomCollection] Registered new searcher Searcher@5bf20a8a
> > >> main{StandardDirectoryReader(segments_acm:1367002775958
> > >> _2f28(4.5):C13583563/4088615 _2gl6(4.5):C2754573/202192
> > >> _2g21(4.5):C1046256/298243 _2ge2(4.5):C835858/208834
> > >> _2gqd(4.5):C383500/35732 _2gmu(4.5):C125197/33714
> _2grl(4.5):C46906/3282
> > >> _2gpj(4.5):C66480/17459 _2gra(4.5):C364/40 _2gr1(4.5):C36064/3442
> > >> _2gqg(4.5):C42504/22410 _2gqm(4.5):C26821/13787
> _2gqu(4.5):C24172/10804
> > >> _2gqy(4.5):C697/231 _2gr2(4.5):C878/382 _2gr7(4.5):C28135/12761
> > >> _2gr9(4.5):C3276/1478 _2grb(4.5):C5/1 _2grc(4.5):C3247/1323
> > _2grd(4.5):C6/1
> > >> _2grf(4.5):C5/2 _2grg(4.5):C23659/11895 _2grh(4.5):C1 _2grj(4.5):C1
> > >> _2grk(4.5):C5160/1982 _2grm(4.5):C1210/531 _2grn(4.5):C3957/1790
> > >> _2gro(4.5):C7734/3504 _2grp(4.5):C220/106 _2grq(4.5):C72751/30166
> > >> _2grr(4.5):C1)}
> > >
> > >
> > I've also shared via Google Drive a more complete log for a period of
> time
> > where this is occurring, as well as our solrconfig.xml in case that is
> > useful.
> >
> > Any ideas on why the Solr commit is not finding any changes despite the
> > clear logging of the adds. For some reason, after hours of this it will
> > find changes and commit everything, including the documents that were
> > skipped previously.
> >
> > Thanks for any assistance!
> >
> > Justin Sweeney
> >
> > solr_commit_issue.log
> > <
> >
> https://docs.google.com/file/d/0B7jKxYrZOSvac21nV0JuRWF0SW8/edit?usp=drive_web
> > >
> >
> > solrconfig.xml
> > <
> >
> https://docs.google.com/file/d/0B7jKxYrZOSvaRUY2QzhUN2tQYmM/edit?usp=drive_web
> > >
> >
> >
>
>
>
> --
> Regards,
> Shalin Shekhar Mangar.
>
