I am taking a snapshot after every commit. From looking at the snapshots,
it does not look like the delay in caused by segments merging because I am
not seeing any large new segments after a commit.
I still can't figure out why there is a 2 minutes gap between "start commit"
and "SolrDelectionPolicy.onCommit". Will changing the deletion policy make
any difference? I am using the default deletion policy now.
Bill
2011/5/21 Erick Erickson <erickerick...@gmail.com>
> Well, committing less offside a possibilty <g>. Here's what's probably
> happening. When you pass certain thresholds, segments are merged which can
> take quite some time. His are you triggering commits? If it's external,
> think about using auto commit instead.
>
> Best
> Erick
> On May 20, 2011 6:04 PM, "Bill Au" <bill.w...@gmail.com> wrote:
> > On my Solr 1.4.1 master I am doing commits regularly at a fixed interval.
> I
> > noticed that from time to time commit will take longer than the commit
> > interval, causing commits to overlap. Then things will get worse as
> commit
> > will take longer and longer. Here is the logs for a long commit:
> >
> >
> > [2011-05-18 23:47:30.071] start
> >
>
> commit(optimize=false,waitFlush=false,waitSearcher=false,expungeDeletes=false)
> > [2011-05-18 23:49:48.119] SolrDeletionPolicy.onCommit: commits:num=2
> > [2011-05-18 23:49:48.119]
> >
>
> commit{dir=/var/opt/resin3/5062/solr/data/index,segFN=segments_5cpa,version=1247782702272,generation=249742,filenames=[_4dqu_2g.del,
> > _4e66.tis, _4e3r.tis, _4e59.nrm, _4e68_1.del, _4e4n.prx, _4e4n.fnm,
> > _4e67.fnm, _4e3r.frq, _4e3r.tii, _4e6d.fnm, _4e6c.prx, _4e68.fdx,
> _4e68.nrm,
> > _4e6a.frq, _4e68.fdt, _4dqu.fnm, _4e4n.tii, _4e69.fdx, _4e69.fdt,
> _4e0e.nrm,
> > _4e4n.tis, _4e6e.fnm, _4e3r.prx, _4e66.fnm, _4e3r.nrm, _4e0e.prx,
> _4e4c.fdx,
> > _4dx1.prx, _4e5v.frq, _4e3r.fdt, _4e4c.tis, _4e41_6.del, _4e6b.tis,
> > _4e6b_1.del, _4e4y_3.del, _4e6b.tii, _4e3r.fdx, _4dx1.nrm, _4e4y.frq,
> > _4e4c.fdt, _4e4c.tii, _4e6d.fdt, _4e5k.fnm, _4e41.fnm, _4e69.fnm,
> _4e67.fdt,
> > _4e0e.tii, _4dty_h.del, _4e6b.fnm, _4e0e_h.del, _4e6d.fdx, _4e67.fdx,
> > _4e0e.tis, _4e5v.nrm, _4dx1.fnm, _4e5v.tii, _4dqu.fdt, segments_5cpa,
> > _4e5v.prx, _4dqu.fdx, _4e59.fnm, _4e6d.prx, _4e59_5.del, _4e4c.prx,
> > _4e4c.nrm, _4e5k.prx, _4e66.fdx, _4dty.frq, _4e6c.frq, _4e5v.tis,
> _4e6e.tii,
> > _4e66.fdt, _4e6b.fdx, _4e68.prx, _4e59.fdx, _4e6e.fdt, _4e41.prx,
> _4dx1.tii,
> > _4dx1.fdt, _4e6b.fdt, _4e5v_4.del, _4e4n.fdt, _4e6e.fdx, _4dx1.fdx,
> > _4e41.nrm, _4e4n.fdx, _4e6e.tis, _4e66.tii, _4e4c.fnm, _4e6b.prx,
> _4e67.prx,
> > _4e0e.fnm, _4e4n.nrm, _4e67.nrm, _4e5k.nrm, _4e6a.prx, _4e68.fnm,
> > _4e4c_4.del, _4dx1.tis, _4e6e.nrm, _4e59.tii, _4e68.tis, _4e67.frq,
> > _4e3r.fnm, _4dty.nrm, _4e4y.prx, _4e6e.prx, _4dty.tis, _4e4y.tis,
> _4e6b.nrm,
> > _4e6a.fdt, _4e4n.frq, _4e6d.frq, _4e59.fdt, _4e6a.fdx, _4e6a.fnm,
> _4dqu.tii,
> > _4e41.tii, _4e67_1.del, _4e41.tis, _4dty.fdt, _4e69.tis, _4dqu.frq,
> > _4dty.fdx, _4dx1.frq, _4e6e.frq, _4e66_1.del, _4e69.prx, _4e6d.tii,
> > _4e5k.tii, _4e0e.fdt, _4dqu.tis, _4e6d.tis, _4e69.nrm, _4dqu.prx,
> _4e4y.fnm,
> > _4e67.tis, _4e69_1.del, _4e6d.nrm, _4e6c.tis, _4e0e.fdx, _4e6c.tii,
> > _4dx1_n.del, _4e5v.fnm, _4e5k.tis, _4e59.tis, _4e67.tii, _4dqu.nrm,
> > _4e5k_8.del, _4e6c.fdx, _4e6c.fdt, _4e41.frq, _4e4y.fdx, _4e69.frq,
> > _4e6a.tis, _4dty.prx, _4e66.frq, _4e5k.frq, _4e6a.tii, _4e69.tii,
> _4e6c.nrm,
> > _4dty.fnm, _4e59.prx, _4e59.frq, _4e66.prx, _4e68.frq, _4e5k.fdx,
> _4e4y.tii,
> > _4e6c.fnm, _4e0e.frq, _4e6b.frq, _4e41.fdt, _4e4n_2.del, _4dty.tii,
> > _4e4y.fdt, _4e66.nrm, _4e4c.frq, _4e6a.nrm, _4e5k.fdt, _4e3r_i.del,
> > _4e5v.fdt, _4e4y.nrm, _4e68.tii, _4e5v.fdx, _4e41.fdx]
> > [2011-05-18 23:49:48.119]
> >
>
> commit{dir=/var/opt/resin3/5062/solr/data/index,segFN=segments_5cpb,version=1247782702273,generation=249743,filenames=[_4dqu_2g.del,
> > _4e66.tis, _4e59.nrm, _4e3r.tis, _4e4n.fnm, _4e67.fnm, _4e3r.tii,
> _4e6d.fnm,
> > _4e68.fdx, _4e68.fdt, _4dqu.fnm, _4e4n.tii, _4e69.fdx, _4e69.fdt,
> _4e4n.tis,
> > _4e6e.fnm, _4e0e.prx, _4e4c.tis, _4e5v.frq, _4e4y_3.del, _4e6b_1.del,
> > _4e4c.tii, _4e6f.fnm, _4e5k.fnm, _4e6c_1.del, _4e41.fnm, _4dx1.fnm,
> > _4e5v.nrm, _4e5v.tii, _4e5v.prx, _4e5k.prx, _4e4c.nrm, _4dty.frq,
> _4e66.fdx,
> > _4e5v.tis, _4e66.fdt, _4e6e.tii, _4e59.fdx, _4e6b.fdx, _4e41.prx,
> _4e6b.fdt,
> > _4e41.nrm, _4e6e.tis, _4e4c.fnm, _4e66.tii, _4e6b.prx, _4e0e.fnm,
> _4e5k.nrm,
> > _4e6a.prx, _4e6e.nrm, _4e59.tii, _4e67.frq, _4dty.nrm, _4e4y.tis,
> _4e6a.fdt,
> > _4e6b.nrm, _4e59.fdt, _4e6a.fdx, _4e41.tii, _4e41.tis, _4e67_1.del,
> > _4dty.fdt, _4dty.fdx, _4e69.tis, _4e66_1.del, _4e6e.frq, _4e5k.tii,
> > _4dqu.prx, _4e67.tis, _4e69_1.del, _4e6c.tis, _4e6c.tii, _4e5v.fnm,
> > _4e5k.tis, _4e59.tis, _4e67.tii, _4e6c.fdx, _4e4y.fdx, _4e41.frq,
> _4e6c.fdt,
> > _4dty.prx, _4e66.frq, _4e69.tii, _4e6c.nrm, _4e59.frq, _4e66.prx,
> _4e5k.fdx,
> > _4e68.frq, _4e4y.tii, _4e4n_2.del, _4e41.fdt, _4e6b.frq, _4e4y.fdt,
> > _4e66.nrm, _4e4c.frq, _4e3r_i.del, _4e5k.fdt, _4e4y.nrm, _4e41.fdx,
> > _4e4n.prx, _4e68_1.del, _4e3r.frq, _4e6f.fdt, _4e6f.fdx, _4e6c.prx,
> > _4e68.nrm, _4e6a.frq, _4e0e.nrm, _4e3r.prx, _4e66.fnm, _4e3r.nrm,
> _4e4c.fdx,
> > _4dx1.prx, _4e3r.fdt, _4e41_6.del, _4e6b.tis, _4e3r.fdx, _4e6b.tii,
> > _4dx1.nrm, _4e4y.frq, _4e4c.fdt, _4e6d.fdt, _4e69.fnm, _4dty_h.del,
> > _4e0e.tii, _4e67.fdt, _4e0e_h.del, _4e6b.fnm, _4e6d.fdx, _4e67.fdx,
> > _4e0e.tis, _4dqu.fdt, segments_5cpb, _4dqu.fdx, _4e59.fnm, _4e59_5.del,
> > _4e6d.prx, _4e4c.prx, _4e6c.frq, _4e68.prx, _4e6e.fdt, _4dx1.tii,
> _4dx1.fdt,
> > _4e4n.fdt, _4e5v_4.del, _4e6e.fdx, _4dx1.fdx, _4e4n.fdx, _4e6f.nrm,
> > _4e4n.nrm, _4e67.prx, _4e67.nrm, _4e68.fnm, _4e4c_4.del, _4dx1.tis,
> > _4e68.tis, _4e3r.fnm, _4e6f.prx, _4e4y.prx, _4dty.tis, _4e6e.prx,
> _4e4n.frq,
> > _4e6d.frq, _4dqu.tii, _4e6a.fnm, _4dx1.frq, _4dqu.frq, _4e69.prx,
> _4e6d.tii,
> > _4e0e.fdt, _4dqu.tis, _4e69.nrm, _4e6d.tis, _4e4y.fnm, _4e0e.fdx,
> _4e6d.nrm,
> > _4dx1_n.del, _4dqu.nrm, _4e6f.tii, _4e5k_8.del, _4e6f.frq, _4e69.frq,
> > _4e6a.tis, _4e6f.tis, _4e5k.frq, _4e6a.tii, _4dty.fnm, _4e59.prx,
> _4e6c.fnm,
> > _4e0e.frq, _4dty.tii, _4e6a.nrm, _4e5v.fdt, _4e68.tii, _4e5v.fdx]
> > [2011-05-18 23:49:48.121] newest commit = 1247782702273
> > [2011-05-18 23:49:49.851] Opening Searcher@488d12e4 main
> > [2011-05-18 23:49:51.534] autowarming Searcher@488d12e4 main from
> > Searcher@64b2933f main
> > [2011-05-18 23:49:51.534]
> >
>
> fieldValueCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,cumulative_hitratio=0.00,cumulative_inserts=0,cumulative_evictions=0}
> > [2011-05-18 23:49:51.535] end_commit_flush
> > [2011-05-18 23:49:51.536] {commit=} 0 141468
> >
> >
> > I noticed that there is a 2 minutes gap between the "start commit ..."
> > message and the "SolrDeletionPolicy.onCommit:.." message. Is Solr
> removing
> > old commits during this time? Is is normal to take this long to delete
> old
> > commits?
> >
> > Bill
>
