в продолжение, вот что говорит log4net:
2009-06-18 19:37:05,145 [5] DEBUG NHibernate.Search.Backend.Impl.Lucene.LuceneWorker — remove from Lucene index: SampleApp.Organization#48
2009-06-18 19:37:16,739 [5] DEBUG NHibernate.Search.Backend.Impl.Lucene.LuceneWorker — Add to Lucene index: SampleApp.Organization#48: Document<stored/uncompressed,indexed<_hibernate_class:SampleApp.Organization, SampleApp> stored/uncompressed,indexed<ID:48> indexed,tokenized<Name:***>>
2009-06-18 19:37:19,693 [5] DEBUG NHibernate.Search.Backend.Impl.Lucene.LuceneWorker — Add to Lucene index: SampleApp.Order#121795: Document<stored/uncompressed,indexed<_hibernate_class:SampleApp.Order, SampleApp> stored/uncompressed,indexed<ID:121795> indexed,tokenized<Name:***> indexed,tokenized<Descrition:***>>
2009-06-18 19:37:20,927 [5] DEBUG NHibernate.Search.Backend.Impl.Lucene.LuceneWorker — Add to Lucene index: SampleApp.Order#121794: Document<stored/uncompressed,indexed<_hibernate_class:SampleApp.Order, SampleApp> stored/uncompressed,indexed<ID:121794> indexed,tokenized<Name:***> indexed,tokenized<Descrition:***>>
2009-06-18 19:37:20,927 [5] DEBUG NHibernate.Search.Backend.Impl.Lucene.LuceneWorker — Add to Lucene index: SampleApp.Order#121796: Document<stored/uncompressed,indexed<_hibernate_class:SampleApp.Order, SampleApp> stored/uncompressed,indexed<ID:121796> indexed,tokenized<Name:***> indexed,tokenized<Descrition:***>>
2009-06-18 19:37:20,927 [5] DEBUG NHibernate.Search.Backend.Impl.Lucene.LuceneWorker — Add to Lucene index: SampleApp.Order#121798: Document<stored/uncompressed,indexed<_hibernate_class:SampleApp.Order, SampleApp> stored/uncompressed,indexed<ID:121798> indexed,tokenized<Name:***> indexed,tokenized<Descrition:***>>
2009-06-18 19:37:20,927 [5] DEBUG NHibernate.Search.Backend.Impl.Lucene.LuceneWorker — Add to Lucene index: SampleApp.Order#121797: Document<stored/uncompressed,indexed<_hibernate_class:SampleApp.Order, SampleApp> stored/uncompressed,indexed<ID:121797> indexed,tokenized<Name:***> indexed,tokenized<Descrition:***>>
2009-06-18 19:37:20,974 [5] DEBUG NHibernate.Transaction.AdoTransaction — IDbTransaction disposed.
2009-06-18 19:37:20,974 [5] DEBUG NHibernate.Impl.SessionImpl — running ISession.Dispose()
2009-06-18 19:37:20,974 [5] DEBUG NHibernate.Impl.SessionImpl — closing session
2009-06-18 19:37:20,974 [5] DEBUG NHibernate.AdoNet.AbstractBatcher — running BatcherImpl.Dispose(true)

что произошло на самом деле:
1. объект Organization#48 был обновлен (на самом деле индексируемое поле не изменилось)
2. удалено 5 объектов Order
3. добавлено 5 новых объектов Order.

меня смущают 3 момента:
1. удаление из индекса занимает 11 секунд!
2. добавление Organization занимает 3 секунды, в строке Name было 6 слов, длинна строки всего 80 символов
3. где же 5 удаленных Order-ов?