You are viewing a plain text version of this content. The canonical link for it is here.
Posted to solr-user@lucene.apache.org by Jamie Johnson <je...@gmail.com> on 2014/04/07 02:37:11 UTC
Commit Within and /update/extract handler
I'm running solr 4.6.0 and am noticing that commitWithin doesn't seem to
work when I am using the /update/extract request handler. It looks like a
commit is happening from the logs, but the documents don't become available
for search until I do a commit manually. Could this be some type of
configuration issue?
Re: Commit Within and /update/extract handler
Posted by Jamie Johnson <je...@gmail.com>.
Thanks Shawn, I appreciate the information.
On Wed, Apr 9, 2014 at 10:27 AM, Shawn Heisey <so...@elyograg.org> wrote:
> On 4/9/2014 7:47 AM, Jamie Johnson wrote:
> > This is being triggered by adding the commitWithin param to
> > ContentStreamUpdateRequest (request.setCommitWithin(10000);). My
> > configuration has autoCommit max time of 15s and openSearcher set to
> false.
> > I'm assuming that changing openSeracher to true should address this, and
> > adding the softCommit = true to the request would make the documents
> > available in the mean time?
>
> My personal opinion: autoCommit should not be used for document
> visibility, even though it CAN be used for it. It belongs in every
> config that uses the transaction log, with openSearcher set to false,
> and carefully considered maxTime and/or maxDocs parameters.
>
> I think it's better to control document visibility entirely manually,
> but if you actually do want to have an automatic commit for document
> visibility, use autoSoftCommit. It doesn't make any sense to disable
> openSearcher on a soft commit, so just leave that out. The docs/time
> intervals for this can be smaller or greater than the intervals for
> autoCommit, depending on your needs.
>
> Any manual commits that you send probably should be soft commits, but
> honestly that doesn't really matter if your auto settings are correct.
>
> Thanks,
> Shawn
>
>
Re: Commit Within and /update/extract handler
Posted by Shawn Heisey <so...@elyograg.org>.
On 4/9/2014 7:47 AM, Jamie Johnson wrote:
> This is being triggered by adding the commitWithin param to
> ContentStreamUpdateRequest (request.setCommitWithin(10000);). My
> configuration has autoCommit max time of 15s and openSearcher set to false.
> I'm assuming that changing openSeracher to true should address this, and
> adding the softCommit = true to the request would make the documents
> available in the mean time?
My personal opinion: autoCommit should not be used for document
visibility, even though it CAN be used for it. It belongs in every
config that uses the transaction log, with openSearcher set to false,
and carefully considered maxTime and/or maxDocs parameters.
I think it's better to control document visibility entirely manually,
but if you actually do want to have an automatic commit for document
visibility, use autoSoftCommit. It doesn't make any sense to disable
openSearcher on a soft commit, so just leave that out. The docs/time
intervals for this can be smaller or greater than the intervals for
autoCommit, depending on your needs.
Any manual commits that you send probably should be soft commits, but
honestly that doesn't really matter if your auto settings are correct.
Thanks,
Shawn
Re: Commit Within and /update/extract handler
Posted by Jamie Johnson <je...@gmail.com>.
This is being triggered by adding the commitWithin param to
ContentStreamUpdateRequest (request.setCommitWithin(10000);). My
configuration has autoCommit max time of 15s and openSearcher set to false.
I'm assuming that changing openSeracher to true should address this, and
adding the softCommit = true to the request would make the documents
available in the mean time?
On Apr 8, 2014 10:02 AM, "Erick Erickson" <er...@gmail.com> wrote:
> Got a clue how it's being generated? Because it's not going to show
> you documents.
>
>
> commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
>
> openSearcher=false and softCommit=false so the documents will be
> invisible. You need one or the other set to true.
>
> What it will do is close the current segment, open a new one and
> truncate the current transaction log. These may be good things but
> they have nothing to do with making docs visible :).
>
> See:
>
> http://searchhub.org/2013/08/23/understanding-transaction-logs-softcommit-and-commit-in-sorlcloud/
>
> Best,
> Erick
>
> On Mon, Apr 7, 2014 at 8:43 PM, Jamie Johnson <je...@gmail.com> wrote:
> > Below is the log showing what I believe to be the commit
> >
> > 07-Apr-2014 23:40:55.846 INFO [catalina-exec-5]
> > org.apache.solr.update.processor.LogUpdateProcessor.finish [forums]
> > webapp=/solr path=/update/extract
> >
> params={uprefix=attr_&literal.source_id=e4bb4bb6-96ab-4f8f-8a2a-1cf37dc1bcce&literal.content_group=File&
> > literal.id
> =e4bb4bb6-96ab-4f8f-8a2a-1cf37dc1bcce&literal.forum_id=3&literal.content_type=application/octet-stream&wt=javabin&literal.uploaded_by=+&version=2&literal.content_type=application/octet-stream&literal.file_name=exclusions}
> > {add=[e4bb4bb6-96ab-4f8f-8a2a-1cf37dc1bcce (1464785652471037952)]} 0 563
> > 07-Apr-2014 23:41:10.847 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.DirectUpdateHandler2.commit start
> >
> commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
> > 07-Apr-2014 23:41:10.847 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IW][commitScheduler-10-thread-1]: commit: start
> > 07-Apr-2014 23:41:10.848 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IW][commitScheduler-10-thread-1]: commit: enter lock
> > 07-Apr-2014 23:41:10.848 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IW][commitScheduler-10-thread-1]: commit: now prepare
> > 07-Apr-2014 23:41:10.848 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IW][commitScheduler-10-thread-1]: prepareCommit: flush
> > 07-Apr-2014 23:41:10.849 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IW][commitScheduler-10-thread-1]: index before flush _y(4.6):C1
> > _10(4.6):C1 _11(4.6):C1 _12(4.6):C1
> > 07-Apr-2014 23:41:10.849 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [DW][commitScheduler-10-thread-1]: commitScheduler-10-thread-1
> > startFullFlush
> > 07-Apr-2014 23:41:10.849 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [DW][commitScheduler-10-thread-1]: anyChanges? numDocsInRam=1
> deletes=true
> > hasTickets:false pendingChangesInFullFlush: false
> > 07-Apr-2014 23:41:10.850 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [DWFC][commitScheduler-10-thread-1]: addFlushableState
> > DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_14,
> > aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 2 ]]
> > 07-Apr-2014 23:41:10.852 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [DWPT][commitScheduler-10-thread-1]: flush postings as segment _14
> numDocs=1
> > 07-Apr-2014 23:41:10.904 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [DWPT][commitScheduler-10-thread-1]: new segment has 0 deleted docs
> > 07-Apr-2014 23:41:10.904 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [DWPT][commitScheduler-10-thread-1]: new segment has no vectors; norms;
> no
> > docValues; prox; freqs
> > 07-Apr-2014 23:41:10.904 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [DWPT][commitScheduler-10-thread-1]: flushedFiles=[_14.nvd,
> > _14_Lucene41_0.pos, _14_Lucene41_0.tip, _14_Lucene41_0.tim, _14.nvm,
> > _14.fdx, _14_Lucene41_0.doc, _14.fnm, _14.fdt]
> > 07-Apr-2014 23:41:10.905 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [DWPT][commitScheduler-10-thread-1]: flushed codec=Lucene46
> > 07-Apr-2014 23:41:10.905 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [DWPT][commitScheduler-10-thread-1]: flushed: segment=_14 ramUsed=0.122
> MB
> > newFlushedSize(includes docstores)=0.003 MB docs/MB=322.937
> > 07-Apr-2014 23:41:10.907 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [DW][commitScheduler-10-thread-1]: publishFlushedSegment seg-private
> > updates=null
> > 07-Apr-2014 23:41:10.907 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IW][commitScheduler-10-thread-1]: publishFlushedSegment
> > 07-Apr-2014 23:41:10.907 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [BD][commitScheduler-10-thread-1]: push deletes 1 deleted terms (unique
> > count=1) bytesUsed=1024 delGen=4 packetCount=1 totBytesUsed=1024
> > 07-Apr-2014 23:41:10.907 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IW][commitScheduler-10-thread-1]: publish sets newSegment delGen=5
> > seg=_14(4.6):C1
> > 07-Apr-2014 23:41:10.908 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IFD][commitScheduler-10-thread-1]: now checkpoint "_y(4.6):C1
> _10(4.6):C1
> > _11(4.6):C1 _12(4.6):C1 _14(4.6):C1" [5 segments ; isCommit = false]
> > 07-Apr-2014 23:41:10.908 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IFD][commitScheduler-10-thread-1]: 0 msec to checkpoint
> > 07-Apr-2014 23:41:10.908 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IW][commitScheduler-10-thread-1]: apply all deletes during flush
> > 07-Apr-2014 23:41:10.908 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [BD][commitScheduler-10-thread-1]: applyDeletes: infos=[_y(4.6):C1,
> > _10(4.6):C1, _11(4.6):C1, _12(4.6):C1, _14(4.6):C1] packetCount=1
> > 07-Apr-2014 23:41:10.909 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [BD][commitScheduler-10-thread-1]: seg=_12(4.6):C1 segGen=3 coalesced
> > deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)]
> > newDelCount=0
> > 07-Apr-2014 23:41:10.909 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [BD][commitScheduler-10-thread-1]: seg=_11(4.6):C1 segGen=3 coalesced
> > deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)]
> > newDelCount=0
> > 07-Apr-2014 23:41:10.909 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [BD][commitScheduler-10-thread-1]: seg=_10(4.6):C1 segGen=3 coalesced
> > deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)]
> > newDelCount=0
> > 07-Apr-2014 23:41:10.909 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [BD][commitScheduler-10-thread-1]: seg=_y(4.6):C1 segGen=3 coalesced
> > deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)]
> > newDelCount=0
> > 07-Apr-2014 23:41:10.910 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [BD][commitScheduler-10-thread-1]: applyDeletes took 2 msec
> > 07-Apr-2014 23:41:10.910 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [BD][commitScheduler-10-thread-1]: prune
> > sis=org.apache.lucene.index.SegmentInfos@6960fd3b minGen=6 packetCount=1
> > 07-Apr-2014 23:41:10.910 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [BD][commitScheduler-10-thread-1]: pruneDeletes: prune 1 packets; 0
> packets
> > remain
> > 07-Apr-2014 23:41:10.910 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [DW][commitScheduler-10-thread-1]: commitScheduler-10-thread-1
> > finishFullFlush success=true
> > 07-Apr-2014 23:41:10.911 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [TMP][commitScheduler-10-thread-1]: findMerges: 5 segments
> > 07-Apr-2014 23:41:10.930 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [TMP][commitScheduler-10-thread-1]: seg=_y(4.6):C1 size=0.038 MB
> [floored]
> > 07-Apr-2014 23:41:10.930 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [TMP][commitScheduler-10-thread-1]: seg=_12(4.6):C1 size=0.020 MB
> > [floored]
> > 07-Apr-2014 23:41:10.931 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [TMP][commitScheduler-10-thread-1]: seg=_10(4.6):C1 size=0.004 MB
> > [floored]
> > 07-Apr-2014 23:41:10.931 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [TMP][commitScheduler-10-thread-1]: seg=_14(4.6):C1 size=0.003 MB
> > [floored]
> > 07-Apr-2014 23:41:10.932 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [TMP][commitScheduler-10-thread-1]: seg=_11(4.6):C1 size=0.003 MB
> > [floored]
> > 07-Apr-2014 23:41:10.932 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [TMP][commitScheduler-10-thread-1]: allowedSegmentCount=1 vs count=5
> > (eligible count=5) tooBigCount=0
> > 07-Apr-2014 23:41:10.933 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [CMS][commitScheduler-10-thread-1]: now merge
> > 07-Apr-2014 23:41:10.933 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [CMS][commitScheduler-10-thread-1]: index: _y(4.6):C1 _10(4.6):C1
> > _11(4.6):C1 _12(4.6):C1 _14(4.6):C1
> > 07-Apr-2014 23:41:10.933 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [CMS][commitScheduler-10-thread-1]: no more merges pending; now return
> > 07-Apr-2014 23:41:10.933 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IW][commitScheduler-10-thread-1]: startCommit(): start
> > 07-Apr-2014 23:41:10.934 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IW][commitScheduler-10-thread-1]: startCommit index=_y(4.6):C1
> _10(4.6):C1
> > _11(4.6):C1 _12(4.6):C1 _14(4.6):C1 changeCount=3
> > 07-Apr-2014 23:41:10.939 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IW][commitScheduler-10-thread-1]: done all syncs: [_y.nvd,
> > _10_Lucene41_0.tip, _12.fdt, _10_Lucene41_0.tim, _11_Lucene41_0.doc,
> > _12.fdx, _12.si, _y.fdt, _y_Lucene41_0.tip, _y.fdx, _y.nvm, _14.fdx,
> > _14.fdt, _11_Lucene41_0.tip, _12_Lucene41_0.doc, _11_Lucene41_0.tim,
> > _11.fdx, _10.nvd, _11.fdt, _10.nvm, _12_Lucene41_0.tip,
> _12_Lucene41_0.pos,
> > _12_Lucene41_0.tim, _12.fnm, _14.fnm, _10.fdt, _14_Lucene41_0.pos, _
> 11.si,
> > _14_Lucene41_0.tip, _y.si, _14_Lucene41_0.tim, _11.nvd,
> _14_Lucene41_0.doc,
> > _10.fdx, _10_Lucene41_0.doc, _11.nvm, _y.fnm, _12.nvd, _14.nvd, _10.fnm,
> _
> > 14.si, _11_Lucene41_0.pos, _14.nvm, _y_Lucene41_0.tim, _10.si,
> > _10_Lucene41_0.pos, _11.fnm, _y_Lucene41_0.pos, _12.nvm,
> _y_Lucene41_0.doc]
> > 07-Apr-2014 23:41:10.940 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IW][commitScheduler-10-thread-1]: commit: pendingCommit != null
> > 07-Apr-2014 23:41:10.971 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IW][commitScheduler-10-thread-1]: commit: wrote segments file
> "segments_25"
> > 07-Apr-2014 23:41:10.971 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IFD][commitScheduler-10-thread-1]: now checkpoint "_y(4.6):C1
> _10(4.6):C1
> > _11(4.6):C1 _12(4.6):C1 _14(4.6):C1" [5 segments ; isCommit = true]
> > 07-Apr-2014 23:41:10.972 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.core.SolrDeletionPolicy.onCommit
> > SolrDeletionPolicy.onCommit: commits: num=2
> > commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@
> /Users/jjohnson/Development/servers/apache-tomee-plus-1.6.0/solr/forums/data/index
> > lockFactory=org.apache.lucene.store.NativeFSLockFactory@455f2a2c;
> > maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_24,generation=76}
> > commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@
> /Users/jjohnson/Development/servers/apache-tomee-plus-1.6.0/solr/forums/data/index
> > lockFactory=org.apache.lucene.store.NativeFSLockFactory@455f2a2c;
> > maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_25,generation=77}
> > 07-Apr-2014 23:41:10.973 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.core.SolrDeletionPolicy.updateCommits newest commit
> > generation = 77
> > 07-Apr-2014 23:41:10.973 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IFD][commitScheduler-10-thread-1]: deleteCommits: now decRef commit
> > "segments_24"
> > 07-Apr-2014 23:41:10.973 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IFD][commitScheduler-10-thread-1]: delete "segments_24"
> > 07-Apr-2014 23:41:10.974 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IFD][commitScheduler-10-thread-1]: 2 msec to checkpoint
> > 07-Apr-2014 23:41:10.974 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IW][commitScheduler-10-thread-1]: commit: done
> > 07-Apr-2014 23:41:10.974 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [DW][commitScheduler-10-thread-1]: anyChanges? numDocsInRam=0
> deletes=false
> > hasTickets:false pendingChangesInFullFlush: false
> > 07-Apr-2014 23:41:10.975 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IW][commitScheduler-10-thread-1]: nrtIsCurrent: infoVersion matches:
> > false; DW changes: false; BD changes: false
> > 07-Apr-2014 23:41:10.975 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IW][commitScheduler-10-thread-1]: flush at getReader
> > 07-Apr-2014 23:41:10.975 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [DW][commitScheduler-10-thread-1]: commitScheduler-10-thread-1
> > startFullFlush
> > 07-Apr-2014 23:41:10.975 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [DW][commitScheduler-10-thread-1]: anyChanges? numDocsInRam=0
> deletes=false
> > hasTickets:false pendingChangesInFullFlush: false
> > 07-Apr-2014 23:41:10.976 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IW][commitScheduler-10-thread-1]: apply all deletes during flush
> > 07-Apr-2014 23:41:10.976 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [BD][commitScheduler-10-thread-1]: applyDeletes: no deletes; skipping
> > 07-Apr-2014 23:41:10.976 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [BD][commitScheduler-10-thread-1]: prune
> > sis=org.apache.lucene.index.SegmentInfos@6960fd3b minGen=6 packetCount=0
> > 07-Apr-2014 23:41:10.978 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IW][commitScheduler-10-thread-1]: return reader version=155
> > reader=StandardDirectoryReader(segments_25:155:nrt _y(4.6):C1 _10(4.6):C1
> > _11(4.6):C1 _12(4.6):C1 _14(4.6):C1)
> > 07-Apr-2014 23:41:10.978 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [DW][commitScheduler-10-thread-1]: commitScheduler-10-thread-1
> > finishFullFlush success=true
> > 07-Apr-2014 23:41:10.978 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.LoggingInfoStream.message
> > [IW][commitScheduler-10-thread-1]: getReader took 3 msec
> > 07-Apr-2014 23:41:10.979 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.search.SolrIndexSearcher.<init> Opening
> Searcher@76a4ccarealtime
> > 07-Apr-2014 23:41:10.980 INFO [commitScheduler-10-thread-1]
> > org.apache.solr.update.DirectUpdateHandler2.commit end_commit_flush
> >
> >
> > On Mon, Apr 7, 2014 at 11:43 AM, Erick Erickson <erickerickson@gmail.com
> >wrote:
> >
> >> What does the call look like? Are you setting opening a new searcher
> >> or not? That should be in the log line where the commit is recorded...
> >>
> >> FWIW,
> >> Erick
> >>
> >> On Sun, Apr 6, 2014 at 5:37 PM, Jamie Johnson <je...@gmail.com>
> wrote:
> >> > I'm running solr 4.6.0 and am noticing that commitWithin doesn't seem
> to
> >> > work when I am using the /update/extract request handler. It looks
> like
> >> a
> >> > commit is happening from the logs, but the documents don't become
> >> available
> >> > for search until I do a commit manually. Could this be some type of
> >> > configuration issue?
> >>
>
Re: Commit Within and /update/extract handler
Posted by Erick Erickson <er...@gmail.com>.
Got a clue how it's being generated? Because it's not going to show
you documents.
commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
openSearcher=false and softCommit=false so the documents will be
invisible. You need one or the other set to true.
What it will do is close the current segment, open a new one and
truncate the current transaction log. These may be good things but
they have nothing to do with making docs visible :).
See:
http://searchhub.org/2013/08/23/understanding-transaction-logs-softcommit-and-commit-in-sorlcloud/
Best,
Erick
On Mon, Apr 7, 2014 at 8:43 PM, Jamie Johnson <je...@gmail.com> wrote:
> Below is the log showing what I believe to be the commit
>
> 07-Apr-2014 23:40:55.846 INFO [catalina-exec-5]
> org.apache.solr.update.processor.LogUpdateProcessor.finish [forums]
> webapp=/solr path=/update/extract
> params={uprefix=attr_&literal.source_id=e4bb4bb6-96ab-4f8f-8a2a-1cf37dc1bcce&literal.content_group=File&
> literal.id=e4bb4bb6-96ab-4f8f-8a2a-1cf37dc1bcce&literal.forum_id=3&literal.content_type=application/octet-stream&wt=javabin&literal.uploaded_by=+&version=2&literal.content_type=application/octet-stream&literal.file_name=exclusions}
> {add=[e4bb4bb6-96ab-4f8f-8a2a-1cf37dc1bcce (1464785652471037952)]} 0 563
> 07-Apr-2014 23:41:10.847 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.DirectUpdateHandler2.commit start
> commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
> 07-Apr-2014 23:41:10.847 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IW][commitScheduler-10-thread-1]: commit: start
> 07-Apr-2014 23:41:10.848 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IW][commitScheduler-10-thread-1]: commit: enter lock
> 07-Apr-2014 23:41:10.848 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IW][commitScheduler-10-thread-1]: commit: now prepare
> 07-Apr-2014 23:41:10.848 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IW][commitScheduler-10-thread-1]: prepareCommit: flush
> 07-Apr-2014 23:41:10.849 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IW][commitScheduler-10-thread-1]: index before flush _y(4.6):C1
> _10(4.6):C1 _11(4.6):C1 _12(4.6):C1
> 07-Apr-2014 23:41:10.849 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [DW][commitScheduler-10-thread-1]: commitScheduler-10-thread-1
> startFullFlush
> 07-Apr-2014 23:41:10.849 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [DW][commitScheduler-10-thread-1]: anyChanges? numDocsInRam=1 deletes=true
> hasTickets:false pendingChangesInFullFlush: false
> 07-Apr-2014 23:41:10.850 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [DWFC][commitScheduler-10-thread-1]: addFlushableState
> DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_14,
> aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 2 ]]
> 07-Apr-2014 23:41:10.852 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [DWPT][commitScheduler-10-thread-1]: flush postings as segment _14 numDocs=1
> 07-Apr-2014 23:41:10.904 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [DWPT][commitScheduler-10-thread-1]: new segment has 0 deleted docs
> 07-Apr-2014 23:41:10.904 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [DWPT][commitScheduler-10-thread-1]: new segment has no vectors; norms; no
> docValues; prox; freqs
> 07-Apr-2014 23:41:10.904 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [DWPT][commitScheduler-10-thread-1]: flushedFiles=[_14.nvd,
> _14_Lucene41_0.pos, _14_Lucene41_0.tip, _14_Lucene41_0.tim, _14.nvm,
> _14.fdx, _14_Lucene41_0.doc, _14.fnm, _14.fdt]
> 07-Apr-2014 23:41:10.905 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [DWPT][commitScheduler-10-thread-1]: flushed codec=Lucene46
> 07-Apr-2014 23:41:10.905 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [DWPT][commitScheduler-10-thread-1]: flushed: segment=_14 ramUsed=0.122 MB
> newFlushedSize(includes docstores)=0.003 MB docs/MB=322.937
> 07-Apr-2014 23:41:10.907 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [DW][commitScheduler-10-thread-1]: publishFlushedSegment seg-private
> updates=null
> 07-Apr-2014 23:41:10.907 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IW][commitScheduler-10-thread-1]: publishFlushedSegment
> 07-Apr-2014 23:41:10.907 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [BD][commitScheduler-10-thread-1]: push deletes 1 deleted terms (unique
> count=1) bytesUsed=1024 delGen=4 packetCount=1 totBytesUsed=1024
> 07-Apr-2014 23:41:10.907 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IW][commitScheduler-10-thread-1]: publish sets newSegment delGen=5
> seg=_14(4.6):C1
> 07-Apr-2014 23:41:10.908 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IFD][commitScheduler-10-thread-1]: now checkpoint "_y(4.6):C1 _10(4.6):C1
> _11(4.6):C1 _12(4.6):C1 _14(4.6):C1" [5 segments ; isCommit = false]
> 07-Apr-2014 23:41:10.908 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IFD][commitScheduler-10-thread-1]: 0 msec to checkpoint
> 07-Apr-2014 23:41:10.908 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IW][commitScheduler-10-thread-1]: apply all deletes during flush
> 07-Apr-2014 23:41:10.908 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [BD][commitScheduler-10-thread-1]: applyDeletes: infos=[_y(4.6):C1,
> _10(4.6):C1, _11(4.6):C1, _12(4.6):C1, _14(4.6):C1] packetCount=1
> 07-Apr-2014 23:41:10.909 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [BD][commitScheduler-10-thread-1]: seg=_12(4.6):C1 segGen=3 coalesced
> deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)]
> newDelCount=0
> 07-Apr-2014 23:41:10.909 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [BD][commitScheduler-10-thread-1]: seg=_11(4.6):C1 segGen=3 coalesced
> deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)]
> newDelCount=0
> 07-Apr-2014 23:41:10.909 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [BD][commitScheduler-10-thread-1]: seg=_10(4.6):C1 segGen=3 coalesced
> deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)]
> newDelCount=0
> 07-Apr-2014 23:41:10.909 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [BD][commitScheduler-10-thread-1]: seg=_y(4.6):C1 segGen=3 coalesced
> deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)]
> newDelCount=0
> 07-Apr-2014 23:41:10.910 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [BD][commitScheduler-10-thread-1]: applyDeletes took 2 msec
> 07-Apr-2014 23:41:10.910 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [BD][commitScheduler-10-thread-1]: prune
> sis=org.apache.lucene.index.SegmentInfos@6960fd3b minGen=6 packetCount=1
> 07-Apr-2014 23:41:10.910 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [BD][commitScheduler-10-thread-1]: pruneDeletes: prune 1 packets; 0 packets
> remain
> 07-Apr-2014 23:41:10.910 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [DW][commitScheduler-10-thread-1]: commitScheduler-10-thread-1
> finishFullFlush success=true
> 07-Apr-2014 23:41:10.911 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [TMP][commitScheduler-10-thread-1]: findMerges: 5 segments
> 07-Apr-2014 23:41:10.930 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [TMP][commitScheduler-10-thread-1]: seg=_y(4.6):C1 size=0.038 MB [floored]
> 07-Apr-2014 23:41:10.930 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [TMP][commitScheduler-10-thread-1]: seg=_12(4.6):C1 size=0.020 MB
> [floored]
> 07-Apr-2014 23:41:10.931 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [TMP][commitScheduler-10-thread-1]: seg=_10(4.6):C1 size=0.004 MB
> [floored]
> 07-Apr-2014 23:41:10.931 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [TMP][commitScheduler-10-thread-1]: seg=_14(4.6):C1 size=0.003 MB
> [floored]
> 07-Apr-2014 23:41:10.932 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [TMP][commitScheduler-10-thread-1]: seg=_11(4.6):C1 size=0.003 MB
> [floored]
> 07-Apr-2014 23:41:10.932 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [TMP][commitScheduler-10-thread-1]: allowedSegmentCount=1 vs count=5
> (eligible count=5) tooBigCount=0
> 07-Apr-2014 23:41:10.933 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [CMS][commitScheduler-10-thread-1]: now merge
> 07-Apr-2014 23:41:10.933 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [CMS][commitScheduler-10-thread-1]: index: _y(4.6):C1 _10(4.6):C1
> _11(4.6):C1 _12(4.6):C1 _14(4.6):C1
> 07-Apr-2014 23:41:10.933 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [CMS][commitScheduler-10-thread-1]: no more merges pending; now return
> 07-Apr-2014 23:41:10.933 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IW][commitScheduler-10-thread-1]: startCommit(): start
> 07-Apr-2014 23:41:10.934 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IW][commitScheduler-10-thread-1]: startCommit index=_y(4.6):C1 _10(4.6):C1
> _11(4.6):C1 _12(4.6):C1 _14(4.6):C1 changeCount=3
> 07-Apr-2014 23:41:10.939 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IW][commitScheduler-10-thread-1]: done all syncs: [_y.nvd,
> _10_Lucene41_0.tip, _12.fdt, _10_Lucene41_0.tim, _11_Lucene41_0.doc,
> _12.fdx, _12.si, _y.fdt, _y_Lucene41_0.tip, _y.fdx, _y.nvm, _14.fdx,
> _14.fdt, _11_Lucene41_0.tip, _12_Lucene41_0.doc, _11_Lucene41_0.tim,
> _11.fdx, _10.nvd, _11.fdt, _10.nvm, _12_Lucene41_0.tip, _12_Lucene41_0.pos,
> _12_Lucene41_0.tim, _12.fnm, _14.fnm, _10.fdt, _14_Lucene41_0.pos, _11.si,
> _14_Lucene41_0.tip, _y.si, _14_Lucene41_0.tim, _11.nvd, _14_Lucene41_0.doc,
> _10.fdx, _10_Lucene41_0.doc, _11.nvm, _y.fnm, _12.nvd, _14.nvd, _10.fnm, _
> 14.si, _11_Lucene41_0.pos, _14.nvm, _y_Lucene41_0.tim, _10.si,
> _10_Lucene41_0.pos, _11.fnm, _y_Lucene41_0.pos, _12.nvm, _y_Lucene41_0.doc]
> 07-Apr-2014 23:41:10.940 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IW][commitScheduler-10-thread-1]: commit: pendingCommit != null
> 07-Apr-2014 23:41:10.971 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IW][commitScheduler-10-thread-1]: commit: wrote segments file "segments_25"
> 07-Apr-2014 23:41:10.971 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IFD][commitScheduler-10-thread-1]: now checkpoint "_y(4.6):C1 _10(4.6):C1
> _11(4.6):C1 _12(4.6):C1 _14(4.6):C1" [5 segments ; isCommit = true]
> 07-Apr-2014 23:41:10.972 INFO [commitScheduler-10-thread-1]
> org.apache.solr.core.SolrDeletionPolicy.onCommit
> SolrDeletionPolicy.onCommit: commits: num=2
> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jjohnson/Development/servers/apache-tomee-plus-1.6.0/solr/forums/data/index
> lockFactory=org.apache.lucene.store.NativeFSLockFactory@455f2a2c;
> maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_24,generation=76}
> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jjohnson/Development/servers/apache-tomee-plus-1.6.0/solr/forums/data/index
> lockFactory=org.apache.lucene.store.NativeFSLockFactory@455f2a2c;
> maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_25,generation=77}
> 07-Apr-2014 23:41:10.973 INFO [commitScheduler-10-thread-1]
> org.apache.solr.core.SolrDeletionPolicy.updateCommits newest commit
> generation = 77
> 07-Apr-2014 23:41:10.973 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IFD][commitScheduler-10-thread-1]: deleteCommits: now decRef commit
> "segments_24"
> 07-Apr-2014 23:41:10.973 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IFD][commitScheduler-10-thread-1]: delete "segments_24"
> 07-Apr-2014 23:41:10.974 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IFD][commitScheduler-10-thread-1]: 2 msec to checkpoint
> 07-Apr-2014 23:41:10.974 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IW][commitScheduler-10-thread-1]: commit: done
> 07-Apr-2014 23:41:10.974 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [DW][commitScheduler-10-thread-1]: anyChanges? numDocsInRam=0 deletes=false
> hasTickets:false pendingChangesInFullFlush: false
> 07-Apr-2014 23:41:10.975 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IW][commitScheduler-10-thread-1]: nrtIsCurrent: infoVersion matches:
> false; DW changes: false; BD changes: false
> 07-Apr-2014 23:41:10.975 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IW][commitScheduler-10-thread-1]: flush at getReader
> 07-Apr-2014 23:41:10.975 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [DW][commitScheduler-10-thread-1]: commitScheduler-10-thread-1
> startFullFlush
> 07-Apr-2014 23:41:10.975 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [DW][commitScheduler-10-thread-1]: anyChanges? numDocsInRam=0 deletes=false
> hasTickets:false pendingChangesInFullFlush: false
> 07-Apr-2014 23:41:10.976 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IW][commitScheduler-10-thread-1]: apply all deletes during flush
> 07-Apr-2014 23:41:10.976 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [BD][commitScheduler-10-thread-1]: applyDeletes: no deletes; skipping
> 07-Apr-2014 23:41:10.976 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [BD][commitScheduler-10-thread-1]: prune
> sis=org.apache.lucene.index.SegmentInfos@6960fd3b minGen=6 packetCount=0
> 07-Apr-2014 23:41:10.978 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IW][commitScheduler-10-thread-1]: return reader version=155
> reader=StandardDirectoryReader(segments_25:155:nrt _y(4.6):C1 _10(4.6):C1
> _11(4.6):C1 _12(4.6):C1 _14(4.6):C1)
> 07-Apr-2014 23:41:10.978 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [DW][commitScheduler-10-thread-1]: commitScheduler-10-thread-1
> finishFullFlush success=true
> 07-Apr-2014 23:41:10.978 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.LoggingInfoStream.message
> [IW][commitScheduler-10-thread-1]: getReader took 3 msec
> 07-Apr-2014 23:41:10.979 INFO [commitScheduler-10-thread-1]
> org.apache.solr.search.SolrIndexSearcher.<init> Opening Searcher@76a4ccarealtime
> 07-Apr-2014 23:41:10.980 INFO [commitScheduler-10-thread-1]
> org.apache.solr.update.DirectUpdateHandler2.commit end_commit_flush
>
>
> On Mon, Apr 7, 2014 at 11:43 AM, Erick Erickson <er...@gmail.com>wrote:
>
>> What does the call look like? Are you setting opening a new searcher
>> or not? That should be in the log line where the commit is recorded...
>>
>> FWIW,
>> Erick
>>
>> On Sun, Apr 6, 2014 at 5:37 PM, Jamie Johnson <je...@gmail.com> wrote:
>> > I'm running solr 4.6.0 and am noticing that commitWithin doesn't seem to
>> > work when I am using the /update/extract request handler. It looks like
>> a
>> > commit is happening from the logs, but the documents don't become
>> available
>> > for search until I do a commit manually. Could this be some type of
>> > configuration issue?
>>
Re: Commit Within and /update/extract handler
Posted by Jamie Johnson <je...@gmail.com>.
Below is the log showing what I believe to be the commit
07-Apr-2014 23:40:55.846 INFO [catalina-exec-5]
org.apache.solr.update.processor.LogUpdateProcessor.finish [forums]
webapp=/solr path=/update/extract
params={uprefix=attr_&literal.source_id=e4bb4bb6-96ab-4f8f-8a2a-1cf37dc1bcce&literal.content_group=File&
literal.id=e4bb4bb6-96ab-4f8f-8a2a-1cf37dc1bcce&literal.forum_id=3&literal.content_type=application/octet-stream&wt=javabin&literal.uploaded_by=+&version=2&literal.content_type=application/octet-stream&literal.file_name=exclusions}
{add=[e4bb4bb6-96ab-4f8f-8a2a-1cf37dc1bcce (1464785652471037952)]} 0 563
07-Apr-2014 23:41:10.847 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.DirectUpdateHandler2.commit start
commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
07-Apr-2014 23:41:10.847 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IW][commitScheduler-10-thread-1]: commit: start
07-Apr-2014 23:41:10.848 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IW][commitScheduler-10-thread-1]: commit: enter lock
07-Apr-2014 23:41:10.848 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IW][commitScheduler-10-thread-1]: commit: now prepare
07-Apr-2014 23:41:10.848 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IW][commitScheduler-10-thread-1]: prepareCommit: flush
07-Apr-2014 23:41:10.849 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IW][commitScheduler-10-thread-1]: index before flush _y(4.6):C1
_10(4.6):C1 _11(4.6):C1 _12(4.6):C1
07-Apr-2014 23:41:10.849 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[DW][commitScheduler-10-thread-1]: commitScheduler-10-thread-1
startFullFlush
07-Apr-2014 23:41:10.849 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[DW][commitScheduler-10-thread-1]: anyChanges? numDocsInRam=1 deletes=true
hasTickets:false pendingChangesInFullFlush: false
07-Apr-2014 23:41:10.850 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[DWFC][commitScheduler-10-thread-1]: addFlushableState
DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_14,
aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 2 ]]
07-Apr-2014 23:41:10.852 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[DWPT][commitScheduler-10-thread-1]: flush postings as segment _14 numDocs=1
07-Apr-2014 23:41:10.904 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[DWPT][commitScheduler-10-thread-1]: new segment has 0 deleted docs
07-Apr-2014 23:41:10.904 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[DWPT][commitScheduler-10-thread-1]: new segment has no vectors; norms; no
docValues; prox; freqs
07-Apr-2014 23:41:10.904 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[DWPT][commitScheduler-10-thread-1]: flushedFiles=[_14.nvd,
_14_Lucene41_0.pos, _14_Lucene41_0.tip, _14_Lucene41_0.tim, _14.nvm,
_14.fdx, _14_Lucene41_0.doc, _14.fnm, _14.fdt]
07-Apr-2014 23:41:10.905 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[DWPT][commitScheduler-10-thread-1]: flushed codec=Lucene46
07-Apr-2014 23:41:10.905 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[DWPT][commitScheduler-10-thread-1]: flushed: segment=_14 ramUsed=0.122 MB
newFlushedSize(includes docstores)=0.003 MB docs/MB=322.937
07-Apr-2014 23:41:10.907 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[DW][commitScheduler-10-thread-1]: publishFlushedSegment seg-private
updates=null
07-Apr-2014 23:41:10.907 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IW][commitScheduler-10-thread-1]: publishFlushedSegment
07-Apr-2014 23:41:10.907 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[BD][commitScheduler-10-thread-1]: push deletes 1 deleted terms (unique
count=1) bytesUsed=1024 delGen=4 packetCount=1 totBytesUsed=1024
07-Apr-2014 23:41:10.907 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IW][commitScheduler-10-thread-1]: publish sets newSegment delGen=5
seg=_14(4.6):C1
07-Apr-2014 23:41:10.908 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IFD][commitScheduler-10-thread-1]: now checkpoint "_y(4.6):C1 _10(4.6):C1
_11(4.6):C1 _12(4.6):C1 _14(4.6):C1" [5 segments ; isCommit = false]
07-Apr-2014 23:41:10.908 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IFD][commitScheduler-10-thread-1]: 0 msec to checkpoint
07-Apr-2014 23:41:10.908 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IW][commitScheduler-10-thread-1]: apply all deletes during flush
07-Apr-2014 23:41:10.908 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[BD][commitScheduler-10-thread-1]: applyDeletes: infos=[_y(4.6):C1,
_10(4.6):C1, _11(4.6):C1, _12(4.6):C1, _14(4.6):C1] packetCount=1
07-Apr-2014 23:41:10.909 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[BD][commitScheduler-10-thread-1]: seg=_12(4.6):C1 segGen=3 coalesced
deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)]
newDelCount=0
07-Apr-2014 23:41:10.909 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[BD][commitScheduler-10-thread-1]: seg=_11(4.6):C1 segGen=3 coalesced
deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)]
newDelCount=0
07-Apr-2014 23:41:10.909 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[BD][commitScheduler-10-thread-1]: seg=_10(4.6):C1 segGen=3 coalesced
deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)]
newDelCount=0
07-Apr-2014 23:41:10.909 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[BD][commitScheduler-10-thread-1]: seg=_y(4.6):C1 segGen=3 coalesced
deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)]
newDelCount=0
07-Apr-2014 23:41:10.910 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[BD][commitScheduler-10-thread-1]: applyDeletes took 2 msec
07-Apr-2014 23:41:10.910 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[BD][commitScheduler-10-thread-1]: prune
sis=org.apache.lucene.index.SegmentInfos@6960fd3b minGen=6 packetCount=1
07-Apr-2014 23:41:10.910 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[BD][commitScheduler-10-thread-1]: pruneDeletes: prune 1 packets; 0 packets
remain
07-Apr-2014 23:41:10.910 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[DW][commitScheduler-10-thread-1]: commitScheduler-10-thread-1
finishFullFlush success=true
07-Apr-2014 23:41:10.911 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[TMP][commitScheduler-10-thread-1]: findMerges: 5 segments
07-Apr-2014 23:41:10.930 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[TMP][commitScheduler-10-thread-1]: seg=_y(4.6):C1 size=0.038 MB [floored]
07-Apr-2014 23:41:10.930 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[TMP][commitScheduler-10-thread-1]: seg=_12(4.6):C1 size=0.020 MB
[floored]
07-Apr-2014 23:41:10.931 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[TMP][commitScheduler-10-thread-1]: seg=_10(4.6):C1 size=0.004 MB
[floored]
07-Apr-2014 23:41:10.931 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[TMP][commitScheduler-10-thread-1]: seg=_14(4.6):C1 size=0.003 MB
[floored]
07-Apr-2014 23:41:10.932 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[TMP][commitScheduler-10-thread-1]: seg=_11(4.6):C1 size=0.003 MB
[floored]
07-Apr-2014 23:41:10.932 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[TMP][commitScheduler-10-thread-1]: allowedSegmentCount=1 vs count=5
(eligible count=5) tooBigCount=0
07-Apr-2014 23:41:10.933 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[CMS][commitScheduler-10-thread-1]: now merge
07-Apr-2014 23:41:10.933 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[CMS][commitScheduler-10-thread-1]: index: _y(4.6):C1 _10(4.6):C1
_11(4.6):C1 _12(4.6):C1 _14(4.6):C1
07-Apr-2014 23:41:10.933 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[CMS][commitScheduler-10-thread-1]: no more merges pending; now return
07-Apr-2014 23:41:10.933 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IW][commitScheduler-10-thread-1]: startCommit(): start
07-Apr-2014 23:41:10.934 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IW][commitScheduler-10-thread-1]: startCommit index=_y(4.6):C1 _10(4.6):C1
_11(4.6):C1 _12(4.6):C1 _14(4.6):C1 changeCount=3
07-Apr-2014 23:41:10.939 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IW][commitScheduler-10-thread-1]: done all syncs: [_y.nvd,
_10_Lucene41_0.tip, _12.fdt, _10_Lucene41_0.tim, _11_Lucene41_0.doc,
_12.fdx, _12.si, _y.fdt, _y_Lucene41_0.tip, _y.fdx, _y.nvm, _14.fdx,
_14.fdt, _11_Lucene41_0.tip, _12_Lucene41_0.doc, _11_Lucene41_0.tim,
_11.fdx, _10.nvd, _11.fdt, _10.nvm, _12_Lucene41_0.tip, _12_Lucene41_0.pos,
_12_Lucene41_0.tim, _12.fnm, _14.fnm, _10.fdt, _14_Lucene41_0.pos, _11.si,
_14_Lucene41_0.tip, _y.si, _14_Lucene41_0.tim, _11.nvd, _14_Lucene41_0.doc,
_10.fdx, _10_Lucene41_0.doc, _11.nvm, _y.fnm, _12.nvd, _14.nvd, _10.fnm, _
14.si, _11_Lucene41_0.pos, _14.nvm, _y_Lucene41_0.tim, _10.si,
_10_Lucene41_0.pos, _11.fnm, _y_Lucene41_0.pos, _12.nvm, _y_Lucene41_0.doc]
07-Apr-2014 23:41:10.940 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IW][commitScheduler-10-thread-1]: commit: pendingCommit != null
07-Apr-2014 23:41:10.971 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IW][commitScheduler-10-thread-1]: commit: wrote segments file "segments_25"
07-Apr-2014 23:41:10.971 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IFD][commitScheduler-10-thread-1]: now checkpoint "_y(4.6):C1 _10(4.6):C1
_11(4.6):C1 _12(4.6):C1 _14(4.6):C1" [5 segments ; isCommit = true]
07-Apr-2014 23:41:10.972 INFO [commitScheduler-10-thread-1]
org.apache.solr.core.SolrDeletionPolicy.onCommit
SolrDeletionPolicy.onCommit: commits: num=2
commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jjohnson/Development/servers/apache-tomee-plus-1.6.0/solr/forums/data/index
lockFactory=org.apache.lucene.store.NativeFSLockFactory@455f2a2c;
maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_24,generation=76}
commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jjohnson/Development/servers/apache-tomee-plus-1.6.0/solr/forums/data/index
lockFactory=org.apache.lucene.store.NativeFSLockFactory@455f2a2c;
maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_25,generation=77}
07-Apr-2014 23:41:10.973 INFO [commitScheduler-10-thread-1]
org.apache.solr.core.SolrDeletionPolicy.updateCommits newest commit
generation = 77
07-Apr-2014 23:41:10.973 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IFD][commitScheduler-10-thread-1]: deleteCommits: now decRef commit
"segments_24"
07-Apr-2014 23:41:10.973 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IFD][commitScheduler-10-thread-1]: delete "segments_24"
07-Apr-2014 23:41:10.974 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IFD][commitScheduler-10-thread-1]: 2 msec to checkpoint
07-Apr-2014 23:41:10.974 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IW][commitScheduler-10-thread-1]: commit: done
07-Apr-2014 23:41:10.974 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[DW][commitScheduler-10-thread-1]: anyChanges? numDocsInRam=0 deletes=false
hasTickets:false pendingChangesInFullFlush: false
07-Apr-2014 23:41:10.975 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IW][commitScheduler-10-thread-1]: nrtIsCurrent: infoVersion matches:
false; DW changes: false; BD changes: false
07-Apr-2014 23:41:10.975 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IW][commitScheduler-10-thread-1]: flush at getReader
07-Apr-2014 23:41:10.975 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[DW][commitScheduler-10-thread-1]: commitScheduler-10-thread-1
startFullFlush
07-Apr-2014 23:41:10.975 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[DW][commitScheduler-10-thread-1]: anyChanges? numDocsInRam=0 deletes=false
hasTickets:false pendingChangesInFullFlush: false
07-Apr-2014 23:41:10.976 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IW][commitScheduler-10-thread-1]: apply all deletes during flush
07-Apr-2014 23:41:10.976 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[BD][commitScheduler-10-thread-1]: applyDeletes: no deletes; skipping
07-Apr-2014 23:41:10.976 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[BD][commitScheduler-10-thread-1]: prune
sis=org.apache.lucene.index.SegmentInfos@6960fd3b minGen=6 packetCount=0
07-Apr-2014 23:41:10.978 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IW][commitScheduler-10-thread-1]: return reader version=155
reader=StandardDirectoryReader(segments_25:155:nrt _y(4.6):C1 _10(4.6):C1
_11(4.6):C1 _12(4.6):C1 _14(4.6):C1)
07-Apr-2014 23:41:10.978 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[DW][commitScheduler-10-thread-1]: commitScheduler-10-thread-1
finishFullFlush success=true
07-Apr-2014 23:41:10.978 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.LoggingInfoStream.message
[IW][commitScheduler-10-thread-1]: getReader took 3 msec
07-Apr-2014 23:41:10.979 INFO [commitScheduler-10-thread-1]
org.apache.solr.search.SolrIndexSearcher.<init> Opening Searcher@76a4ccarealtime
07-Apr-2014 23:41:10.980 INFO [commitScheduler-10-thread-1]
org.apache.solr.update.DirectUpdateHandler2.commit end_commit_flush
On Mon, Apr 7, 2014 at 11:43 AM, Erick Erickson <er...@gmail.com>wrote:
> What does the call look like? Are you setting opening a new searcher
> or not? That should be in the log line where the commit is recorded...
>
> FWIW,
> Erick
>
> On Sun, Apr 6, 2014 at 5:37 PM, Jamie Johnson <je...@gmail.com> wrote:
> > I'm running solr 4.6.0 and am noticing that commitWithin doesn't seem to
> > work when I am using the /update/extract request handler. It looks like
> a
> > commit is happening from the logs, but the documents don't become
> available
> > for search until I do a commit manually. Could this be some type of
> > configuration issue?
>
Re: Commit Within and /update/extract handler
Posted by Erick Erickson <er...@gmail.com>.
What does the call look like? Are you setting opening a new searcher
or not? That should be in the log line where the commit is recorded...
FWIW,
Erick
On Sun, Apr 6, 2014 at 5:37 PM, Jamie Johnson <je...@gmail.com> wrote:
> I'm running solr 4.6.0 and am noticing that commitWithin doesn't seem to
> work when I am using the /update/extract request handler. It looks like a
> commit is happening from the logs, but the documents don't become available
> for search until I do a commit manually. Could this be some type of
> configuration issue?
Re: Commit Within and /update/extract handler
Posted by Erick Erickson <er...@gmail.com>.
You say you see the commit happen in the log, is openSearcher
specified? This sounds like you're somehow getting a commit
with openSearcher=false...
Best,
Erick
On Sun, Apr 6, 2014 at 5:37 PM, Jamie Johnson <je...@gmail.com> wrote:
> I'm running solr 4.6.0 and am noticing that commitWithin doesn't seem to
> work when I am using the /update/extract request handler. It looks like a
> commit is happening from the logs, but the documents don't become available
> for search until I do a commit manually. Could this be some type of
> configuration issue?