MassIndexer not working on latest SNAPSHOT

Hello,

Since i update on the last SNAPSHOT version, my massIndexer index nothing.
No error appears in the failure handler.
if i use Kibana i see some new indexes like this

  • myClassName-000001
  • myClassName-write

Here a part of my code

SearchSession sSession = Search.session((EntityManager) session);
searchSession.massIndexer(MyClass.class).purgeAllOnStart(true / false).startAndWait();

any tips ? :slight_smile:
Thanks

Hello,

It’s a feature, and it was published in Beta5, so it’s not just in the latest snapshot.
You’ll find more details in the announcement:

Aliases for Elasticsearch indexes

As of HSEARCH-3791, Elasticsearch indexes are now accessed through aliases only. Hibernate Search relies on two aliases for each index: one for writes ( <myindex>-write ) and one for reads ( <myindex>-read ).

This setup is a first step towards introducing, in a future version of Hibernate Search, a “zero-downtime” reindexing where search queries still return results while reindexing. See this section of the reference documentation for more information, in particular regarding how to change the name of the aliases.

As a result of this change, you will need to either:

  • manually create the two aliases for each index;
  • or drop your indexes and have Hibernate Search re-create empty indexes on startup: it will create the aliases. In this case, you will also need to reindex.

Note that Hibernate Search will warn you something is wrong with your old setup (missing aliases in particular) if you use schema validation. If you’re using the snapshot, I’d suggest you build the documentation and have a look at the “Schema management” section; in particular, you can trigger validation of the schema explicitly when you know the Elasticsearch cluster is up, using SearchSchemaManager.validate().

Execute this to build the documentation from source:

mvn clean install -DskipTests -pl documentation -am
xdg-open ./documentation/target/asciidoctor/en-US/html_single/index.html

(The second line just opens the documentation in your browser, it will probably only work on Linux).

1 Like

Thanks for the quick reply (as always), i used to see this part of the documentation and it’s really nice to implement it this way ! :smiley:

But my issue is i can’t index my entities

Look the Monitor output.

2020-03-12 13:10:01,168 o.h.s.m.o.m.i.LoggingMassIndexingMonitor  [I] HSEARCH000028: Reindexed 0 entities
2020-03-12 13:10:01,183 o.h.s.m.o.m.i.LoggingMassIndexingMonitor  [I] HSEARCH000028: Reindexed 0 entities
2020-03-12 13:10:01,199 o.h.s.m.o.m.i.LoggingMassIndexingMonitor  [I] HSEARCH000028: Reindexed 0 entities

Of course my entites are here (in the database), and when i use the instance of my session (the same used to build the SearchSession) i’m able to load/get thoose entities manually, so i really don’t get why the MassIndexer see nothing to push to the cluster.

If you rely on multi-tenancy, make sure you create the mass indexer with the right tenant ID.

If not… can you provide more logs? There should be initial logs stating “Going to reindex X entities”. If X is non-zero, Hibernate Search managed to access the database, so the problem is probably not there. You can also enable the TRACE level for the logger org.hibernate.search.mapper.orm.massindexing to get more logs.

A possible explanation is that mass indexing failed. If you used startAndWait() to start the mass indexer, it should throw an exception on failure. If you used start(), it won’t throw an exception: the exception will be pushed to the returned CompletableFuture.

Here some logs.

2020-03-12 14:42:47,334         o.h.s.m.o.m.impl.MassIndexerImpl  [D] Targets for indexing job: [org.hibernate.search.mapper.orm.mapping.impl.HibernateOrmIndexedTypeContext@6827395a, org.hibernate.search.mapper.orm.mapping.impl.HibernateOrmIndexedTypeContext@22e6a0e2, org.hibernate.search.mapper.orm.mapping.impl.HibernateOrmIndexedTypeContext@57902d94, org.hibernate.search.mapper.orm.mapping.impl.HibernateOrmIndexedTypeContext@40e66634]
2020-03-12 14:42:47,350 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/clientphysique-write/_refresh' with query parameters POST and 0 objects in payload in 1ms. Response had status 200 'OK'. Request body: <>. Response body: <{"_shards":{"total":2,"successful":1,"failed":0}}>
2020-03-12 14:42:47,366 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/clientphysique-write/_delete_by_query' with query parameters {conflicts=proceed} and 1 objects in payload in 4ms. Response had status 200 'OK'. Request body: <{"query":{"bool":{"must":{"match_all":POST},"filter":[{"term":{"_tenant_id":""}}]}}}>. Response body: <{"took":0,"timed_out":false,"total":0,"deleted":0,"batches":0,"version_conflicts":0,"noops":0,"retries":{"bulk":0,"search":0},"throttled_millis":0,"requests_per_second":-1.0,"throttled_until_millis":0,"failures":[]}>
2020-03-12 14:42:47,366 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/clientmoral-write/_refresh' with query parameters POST and 0 objects in payload in 2ms. Response had status 200 'OK'. Request body: <>. Response body: <{"_shards":{"total":2,"successful":1,"failed":0}}>
2020-03-12 14:42:47,366 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/sousproduit-write/_refresh' with query parameters POST and 0 objects in payload in 2ms. Response had status 200 'OK'. Request body: <>. Response body: <{"_shards":{"total":2,"successful":1,"failed":0}}>
2020-03-12 14:42:47,366 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/depot-write/_refresh' with query parameters POST and 0 objects in payload in 2ms. Response had status 200 'OK'. Request body: <>. Response body: <{"_shards":{"total":2,"successful":1,"failed":0}}>
2020-03-12 14:42:47,381 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/clientmoral-write/_delete_by_query' with query parameters {conflicts=proceed} and 1 objects in payload in 3ms. Response had status 200 'OK'. Request body: <{"query":{"bool":{"must":{"match_all":POST},"filter":[{"term":{"_tenant_id":""}}]}}}>. Response body: <{"took":0,"timed_out":false,"total":0,"deleted":0,"batches":0,"version_conflicts":0,"noops":0,"retries":{"bulk":0,"search":0},"throttled_millis":0,"requests_per_second":-1.0,"throttled_until_millis":0,"failures":[]}>
2020-03-12 14:42:47,381 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/sousproduit-write/_delete_by_query' with query parameters {conflicts=proceed} and 1 objects in payload in 3ms. Response had status 200 'OK'. Request body: <{"query":{"bool":{"must":{"match_all":POST},"filter":[{"term":{"_tenant_id":""}}]}}}>. Response body: <{"took":0,"timed_out":false,"total":0,"deleted":0,"batches":0,"version_conflicts":0,"noops":0,"retries":{"bulk":0,"search":0},"throttled_millis":0,"requests_per_second":-1.0,"throttled_until_millis":0,"failures":[]}>
2020-03-12 14:42:47,381 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/depot-write/_delete_by_query' with query parameters {conflicts=proceed} and 1 objects in payload in 2ms. Response had status 200 'OK'. Request body: <{"query":{"bool":{"must":{"match_all":POST},"filter":[{"term":{"_tenant_id":""}}]}}}>. Response body: <{"took":0,"timed_out":false,"total":0,"deleted":0,"batches":0,"version_conflicts":0,"noops":0,"retries":{"bulk":0,"search":0},"throttled_millis":0,"requests_per_second":-1.0,"throttled_until_millis":0,"failures":[]}>
2020-03-12 14:42:47,381 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/clientmoral-write/_forcemerge' with query parameters POST and 0 objects in payload in 2ms. Response had status 200 'OK'. Request body: <>. Response body: <{"_shards":{"total":2,"successful":1,"failed":0}}>
2020-03-12 14:42:47,381 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/clientphysique-write/_forcemerge' with query parameters POST and 0 objects in payload in 3ms. Response had status 200 'OK'. Request body: <>. Response body: <{"_shards":{"total":2,"successful":1,"failed":0}}>
2020-03-12 14:42:47,381 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/sousproduit-write/_forcemerge' with query parameters POST and 0 objects in payload in 2ms. Response had status 200 'OK'. Request body: <>. Response body: <{"_shards":{"total":2,"successful":1,"failed":0}}>
2020-03-12 14:42:47,381 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/depot-write/_forcemerge' with query parameters POST and 0 objects in payload in 2ms. Response had status 200 'OK'. Request body: <>. Response body: <{"_shards":{"total":2,"successful":1,"failed":0}}>
2020-03-12 14:42:47,397 o.m.i.IdentifierConsumerDocumentProducer  [T] created
2020-03-12 14:42:50,599 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:51,021 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:51,450 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:51,793 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:52,090 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:52,278 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:52,278      o.h.s.m.o.m.impl.IdentifierProducer  [T] created
2020-03-12 14:42:52,278  o.h.s.m.o.m.i.BatchTransactionalContext  [T] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2020-03-12 14:42:52,278      o.h.s.m.o.m.impl.IdentifierProducer  [T] started
2020-03-12 14:42:52,324 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:52,324 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:52,324 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:52,324 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:52,324 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:52,324 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:52,324  o.h.s.m.o.m.impl.BatchIndexingWorkspace  [D] Indexing for ClientPhysique is done
2020-03-12 14:42:52,324 o.m.i.IdentifierConsumerDocumentProducer  [T] created
2020-03-12 14:42:53,606 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:53,871 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:54,027 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:54,183 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:54,355 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:54,522      o.h.s.m.o.m.impl.IdentifierProducer  [T] created
2020-03-12 14:42:54,522 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:54,522  o.h.s.m.o.m.i.BatchTransactionalContext  [T] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2020-03-12 14:42:54,522      o.h.s.m.o.m.impl.IdentifierProducer  [T] started
2020-03-12 14:42:54,522 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:54,522 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:54,522 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:54,522 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:54,522 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:54,522 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:54,522  o.h.s.m.o.m.impl.BatchIndexingWorkspace  [D] Indexing for ClientMoral is done
2020-03-12 14:42:54,522 o.m.i.IdentifierConsumerDocumentProducer  [T] created
2020-03-12 14:42:55,968 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:55,968 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:55,968 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:55,968      o.h.s.m.o.m.impl.IdentifierProducer  [T] created
2020-03-12 14:42:55,968 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:55,968  o.h.s.m.o.m.i.BatchTransactionalContext  [T] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2020-03-12 14:42:55,968 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:55,968 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:55,968      o.h.s.m.o.m.impl.IdentifierProducer  [T] started
2020-03-12 14:42:55,983 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:55,983 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:55,983 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:55,983 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:55,983 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:55,983 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:55,983  o.h.s.m.o.m.impl.BatchIndexingWorkspace  [D] Indexing for SousProduit is done
2020-03-12 14:42:55,983 o.m.i.IdentifierConsumerDocumentProducer  [T] created
2020-03-12 14:42:55,983 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:55,983 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:55,983 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:55,983 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:55,983      o.h.s.m.o.m.impl.IdentifierProducer  [T] created
2020-03-12 14:42:55,983  o.h.s.m.o.m.i.BatchTransactionalContext  [T] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2020-03-12 14:42:55,983 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:55,983 o.m.i.IdentifierConsumerDocumentProducer  [T] started
2020-03-12 14:42:55,983      o.h.s.m.o.m.impl.IdentifierProducer  [T] started
2020-03-12 14:42:55,983 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:55,983 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:55,983 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:55,983 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:55,983 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:55,983 o.m.i.IdentifierConsumerDocumentProducer  [T] finished
2020-03-12 14:42:55,983  o.h.s.m.o.m.impl.BatchIndexingWorkspace  [D] Indexing for Depot is done
2020-03-12 14:42:55,983 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/clientphysique-write/_flush' with query parameters POST and 0 objects in payload in 2ms. Response had status 200 'OK'. Request body: <>. Response body: <{"_shards":{"total":2,"successful":1,"failed":0}}>
2020-03-12 14:42:55,983 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/clientmoral-write/_flush' with query parameters POST and 0 objects in payload in 2ms. Response had status 200 'OK'. Request body: <>. Response body: <{"_shards":{"total":2,"successful":1,"failed":0}}>
2020-03-12 14:42:55,983 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/sousproduit-write/_flush' with query parameters POST and 0 objects in payload in 1ms. Response had status 200 'OK'. Request body: <>. Response body: <{"_shards":{"total":2,"successful":1,"failed":0}}>
2020-03-12 14:42:55,999 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/depot-write/_flush' with query parameters POST and 0 objects in payload in 2ms. Response had status 200 'OK'. Request body: <>. Response body: <{"_shards":{"total":2,"successful":1,"failed":0}}>
2020-03-12 14:42:55,999 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/clientphysique-write/_refresh' with query parameters POST and 0 objects in payload in 3ms. Response had status 200 'OK'. Request body: <>. Response body: <{"_shards":{"total":2,"successful":1,"failed":0}}>
2020-03-12 14:42:55,999 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/clientmoral-write/_refresh' with query parameters POST and 0 objects in payload in 3ms. Response had status 200 'OK'. Request body: <>. Response body: <{"_shards":{"total":2,"successful":1,"failed":0}}>
2020-03-12 14:42:55,999 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/sousproduit-write/_refresh' with query parameters POST and 0 objects in payload in 2ms. Response had status 200 'OK'. Request body: <>. Response body: <{"_shards":{"total":2,"successful":1,"failed":0}}>
2020-03-12 14:42:55,999 o.hibernate.search.elasticsearch.request  [T] HSEARCH400093: Executed Elasticsearch HTTP POST request to path '/depot-write/_refresh' with query parameters POST and 0 objects in payload in 2ms. Response had status 200 'OK'. Request body: <>. Response body: <{"_shards":{"total":2,"successful":1,"failed":0}}>
2020-03-12 14:42:55,999 o.h.s.m.o.m.i.LoggingMassIndexingMonitor  [I] HSEARCH000028: Reindexed 0 entities

About my session, in local i’am with an empty tenantIdentifier but when i use the session i can load my entities, so i assume the SearchSession is working the same way.

session = sessionFactory.withOptions().tenantIdentifier(crpcen).openSession();
searchSession = Search.session((EntityManager) session);
// session.get(xxx.class, 1l) => OK

And of course i was using the startAndWait()

Your logs lack a line with “going to fetch X primary keys”, which means something failed before it even got there, but the failure wasn’t reported for some reason…
Are you using a custom MassIndexingFailureHandler or FailureHandler that would swallow the exception?

Honestly no, i disabled my failure Handler in my HibernateConfiguration.
Can you point me the class who load entities during the indexation ?

This should detect how many entities must be loaded and fetch the identifiers:

org.hibernate.search.mapper.orm.massindexing.impl.IdentifierProducer#loadAllIdentifiers

This should load the entities:

org.hibernate.search.mapper.orm.massindexing.impl.IdentifierConsumerDocumentProducer#loadAllFromQueue

Thank you for the pointer, i figure out what was wrong !

In Hibernate 5.4.3 there is implementation for the createQuery with CriteriaQuery

@Override
	@SuppressWarnings("unchecked")
	public <T> QueryImplementor<T> createQuery(CriteriaQuery<T> criteriaQuery) {
		checkOpen();
		try {
			return (QueryImplementor<T>) criteriaCompiler().compile( (CompilableCriteria) criteriaQuery );
		}
		catch ( RuntimeException e ) {
			throw getExceptionConverter().convert( e );
		}
	}

And then…

private void loadAllIdentifiers(final StatelessSession session) throws InterruptedException {
		long totalCount = createTotalCountQuery( session ).uniqueResult();

The NoSuchMethodException was silently ignore.

We just published Hibernate Search 6.0.0.Beta5.

This release mainly changes the way the Elasticsearch backend accesses indexes, introduces delayed commits and near-real-time queries for the Lucene backend, and renames a few methods in the Search DSL. It also includes upgrades to Lucene 8.4, Elasticsearch 7.6 and Hibernate ORM 5.4.12.Final.

After reading the doc… (my bad) i upgrade to 5.4.12 and it’s ok, but i don’t understand where this exception is swallow

It endup in CancellableExecutionCompletableFuture

Thanks for the feedback. The throwable was not caught because it’s an Error (which shouldn’t normally be caught), and it seems we didn’t make sure to report Errors one way or another. We’ll change that: https://hibernate.atlassian.net/browse/HSEARCH-3864

1 Like

thx @yrodiere :relaxed: