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 <erickerick...@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 <jej2...@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?
>
