[JIRA] (HSEARCH-4687) Fix flaky test org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT(coord-outbox-default-database-cockroachdb)
by Yoann Rodière (JIRA)
Yoann Rodière ( https://hibernate.atlassian.net/secure/ViewProfile.jspa?accountId=557058%... ) *created* an issue
Hibernate Search ( https://hibernate.atlassian.net/browse/HSEARCH?atlOrigin=eyJpIjoiZTYxZGI3... ) / Task ( https://hibernate.atlassian.net/browse/HSEARCH-4687?atlOrigin=eyJpIjoiZTY... ) HSEARCH-4687 ( https://hibernate.atlassian.net/browse/HSEARCH-4687?atlOrigin=eyJpIjoiZTY... ) Fix flaky test org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT(coord-outbox-default-database-cockroachdb) ( https://hibernate.atlassian.net/browse/HSEARCH-4687?atlOrigin=eyJpIjoiZTY... )
Issue Type: Task Assignee: Yoann Rodière ( https://hibernate.atlassian.net/secure/ViewProfile.jspa?accountId=557058%... ) Created: 26/Aug/2022 02:35 AM Priority: Major Reporter: Yoann Rodière ( https://hibernate.atlassian.net/secure/ViewProfile.jspa?accountId=557058%... )
See https://ci.hibernate.org/blue/organizations/jenkins/hibernate-search/deta... ( https://ci.hibernate.org/blue/organizations/jenkins/hibernate-search/deta... ) :
Error
Condition with alias 'Waiting for indexing assertions' didn't complete within 15 seconds because assertion condition defined as a org.hibernate.search.util.impl.integrationtest.common.rule.VerifyingStubBackendBehavior Expected [creation of a ADD_OR_UPDATE work on document 'IndexedEntity#2962'].
Stacktrace
org.awaitility.core.ConditionTimeoutException: Condition with alias 'Waiting for indexing assertions' didn't complete within 15 seconds because assertion condition defined as a org.hibernate.search.util.impl.integrationtest.common.rule.VerifyingStubBackendBehavior Expected [creation of a ADD_OR_UPDATE work on document 'IndexedEntity#2962'].
at org.awaitility.core.ConditionAwaiter.await(ConditionAwaiter.java:167)
at org.awaitility.core.AssertionCondition.await(AssertionCondition.java:119)
at org.awaitility.core.AssertionCondition.await(AssertionCondition.java:31)
at org.awaitility.core.ConditionFactory.until(ConditionFactory.java:985)
at org.awaitility.core.ConditionFactory.untilAsserted(ConditionFactory.java:769)
at org.hibernate.search.util.impl.integrationtest.common.rule.BackendIndexingWorkExpectations.awaitIndexingAssertions(BackendIndexingWorkExpectations.java:67)
at org.hibernate.search.util.impl.integrationtest.common.rule.VerifyingStubBackendBehavior.lambda$verifyExpectationsMet$7(VerifyingStubBackendBehavior.java:227)
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:53)
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:33)
at org.hibernate.search.util.impl.integrationtest.common.rule.VerifyingStubBackendBehavior.verifyExpectationsMet(VerifyingStubBackendBehavior.java:226)
at org.hibernate.search.util.impl.integrationtest.common.rule.BackendMock.verifyExpectationsMet(BackendMock.java:94)
at org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT.agentExpired(OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT.java:174)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:568)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at org.hibernate.search.util.impl.integrationtest.common.rule.BackendMock$1.evaluate(BackendMock.java:52)
at org.hibernate.search.util.impl.test.rule.StaticCounters$1.evaluate(StaticCounters.java:63)
at org.hibernate.search.util.impl.integrationtest.common.rule.MappingSetupHelper$1.evaluate(MappingSetupHelper.java:74)
at org.hibernate.search.util.impl.integrationtest.common.TestConfigurationProvider$1.evaluate(TestConfigurationProvider.java:45)
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
at org.junit.runners.Suite.runChild(Suite.java:128)
at org.junit.runners.Suite.runChild(Suite.java:27)
at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
at org.apache.maven.surefire.junitcore.JUnitCore.run(JUnitCore.java:55)
at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:137)
at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:107)
at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:83)
at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:75)
at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:158)
at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:456)
at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:169)
at org.apache.maven.surefire.booter.ForkedBooter.run(ForkedBooter.java:595)
at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:581)
Caused by: java.lang.AssertionError: Expected [creation of a ADD_OR_UPDATE work on document 'IndexedEntity#2962']
at org.junit.Assert.fail(Assert.java:89)
at org.hibernate.search.util.impl.integrationtest.common.rule.CallQueue.verifyExpectationsMet(CallQueue.java:234)
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:53)
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:92)
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:73)
at org.hibernate.search.util.impl.integrationtest.common.rule.VerifyingStubBackendBehavior.lambda$verifyExpectationsMet$6(VerifyingStubBackendBehavior.java:229)
at org.awaitility.core.AssertionCondition.lambda$new$0(AssertionCondition.java:53)
at org.awaitility.core.ConditionAwaiter$ConditionPoller.call(ConditionAwaiter.java:248)
at org.awaitility.core.ConditionAwaiter$ConditionPoller.call(ConditionAwaiter.java:235)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:833)
Suppressed: java.lang.AssertionError: Expected [creation of a ADD_OR_UPDATE work on document 'IndexedEntity#2963']
... 13 more
Suppressed: java.lang.AssertionError: Expected [creation of a ADD_OR_UPDATE work on document 'IndexedEntity#2960']
... 13 more
Suppressed: java.lang.AssertionError: Expected [creation of a ADD_OR_UPDATE work on document 'IndexedEntity#2961']
... 13 more
[...]
Suppressed: java.lang.AssertionError: Expected [creation of a ADD_OR_UPDATE work on document 'IndexedEntity#2997']
... 13 more
Suppressed: java.lang.AssertionError: Expected [creation of a ADD_OR_UPDATE work on document 'IndexedEntity#2998']
... 13 more
Suppressed: java.lang.AssertionError: Expected [execution of a ADD_OR_UPDATE work on document 'IndexedEntity#2962']
at org.junit.Assert.fail(Assert.java:89)
at org.hibernate.search.util.impl.integrationtest.common.rule.CallQueue.verifyExpectationsMet(CallQueue.java:234)
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:53)
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:92)
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:73)
at org.hibernate.search.util.impl.integrationtest.common.rule.VerifyingStubBackendBehavior.lambda$verifyExpectationsMet$6(VerifyingStubBackendBehavior.java:231)
... 7 more
Suppressed: java.lang.AssertionError: Expected [execution of a ADD_OR_UPDATE work on document 'IndexedEntity#2963']
at org.junit.Assert.fail(Assert.java:89)
at org.hibernate.search.util.impl.integrationtest.common.rule.CallQueue.verifyExpectationsMet(CallQueue.java:234)
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:53)
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:92)
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:73)
at org.hibernate.search.util.impl.integrationtest.common.rule.VerifyingStubBackendBehavior.lambda$verifyExpectationsMet$6(VerifyingStubBackendBehavior.java:231)
... 7 more
Suppressed: java.lang.AssertionError: Expected [execution of a ADD_OR_UPDATE work on document 'IndexedEntity#2960']
at org.junit.Assert.fail(Assert.java:89)
at org.hibernate.search.util.impl.integrationtest.common.rule.CallQueue.verifyExpectationsMet(CallQueue.java:234)
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:53)
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:92)
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:73)
at org.hibernate.search.util.impl.integrationtest.common.rule.VerifyingStubBackendBehavior.lambda$verifyExpectationsMet$6(VerifyingStubBackendBehavior.java:231)
... 7 more
Suppressed: java.lang.AssertionError: Expected [execution of a ADD_OR_UPDATE work on document 'IndexedEntity#2961']
at org.junit.Assert.fail(Assert.java:89)
at org.hibernate.search.util.impl.integrationtest.common.rule.CallQueue.verifyExpectationsMet(CallQueue.java:234)
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:53)
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:92)
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:73)
at org.hibernate.search.util.impl.integrationtest.common.rule.VerifyingStubBackendBehavior.lambda$verifyExpectationsMet$6(VerifyingStubBackendBehavior.java:231)
... 7 more
Suppressed: java.lang.AssertionError: Expected [execution of a ADD_OR_UPDATE work on document 'IndexedEntity#2966']
at org.junit.Assert.fail(Assert.java:89)
at org.hibernate.search.util.impl.integrationtest.common.rule.CallQueue.verifyExpectationsMet(CallQueue.java:234)
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:53)
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:92)
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:73)
at org.hibernate.search.util.impl.integrationtest.common.rule.VerifyingStubBackendBehavior.lambda$verifyExpectationsMet$6(VerifyingStubBackendBehavior.java:231)
... 7 more
Suppressed: java.lang.AssertionError: Expected [execution of a ADD_OR_UPDATE work on document 'IndexedEntity#2967']
at org.junit.Assert.fail(Assert.java:89)
at org.hibernate.search.util.impl.integrationtest.common.rule.CallQueue.verifyExpectationsMet(CallQueue.java:234)
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:53)
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:92)
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:73)
at org.hibernate.search.util.impl.integrationtest.common.rule.VerifyingStubBackendBehavior.lambda$verifyExpectationsMet$6(VerifyingStubBackendBehavior.java:231)
... 7 more
[...]
Suppressed: java.lang.AssertionError: Expected [execution of a ADD_OR_UPDATE work on document 'IndexedEntity#2998']
at org.junit.Assert.fail(Assert.java:89)
at org.hibernate.search.util.impl.integrationtest.common.rule.CallQueue.verifyExpectationsMet(CallQueue.java:234)
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:53)
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:92)
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:73)
at org.hibernate.search.util.impl.integrationtest.common.rule.VerifyingStubBackendBehavior.lambda$verifyExpectationsMet$6(VerifyingStubBackendBehavior.java:231)
... 7 more
Standard Output
08:12:39,180 (main) WARN CachingRegionFactory:48 - org.hibernate.testing.cache.CachingRegionFactory should be only used for testing.
08:12:39,181 (main) WARN pooling:75 - HHH10001002: Using Hibernate built-in connection pool (not for production use!)
08:12:39,181 (main) INFO pooling:119 - HHH10001005: using driver [org.postgresql.Driver] at URL [jdbc:postgresql://localhost:26257/defaultdb?sslmode=disable]
08:12:39,181 (main) INFO pooling:128 - HHH10001001: Connection properties: {password=****, user=root}
08:12:39,181 (main) INFO pooling:132 - HHH10001003: Autocommit mode: false
08:12:39,181 (main) INFO DriverManagerConnectionProviderImpl:322 - HHH000115: Hibernate connection pool size: 31 (min=1)
08:12:39,184 (main) INFO Dialect:175 - HHH000400: Using dialect: org.hibernate.dialect.CockroachDB201Dialect
08:12:39,187 (main) INFO HibernateSearchPreIntegrationService:91 - HSEARCH000034: Hibernate Search version 6.2.0-SNAPSHOT
08:12:39,188 (main) DEBUG OutboxPollingOutboxEventAdditionalJaxbMappingProducer:146 - HSEARCH850001: Generated entity mapping for outbox events used in the outbox-polling coordination strategy: <?xml version="1.0" encoding="UTF-8"?>
<hibernate-mapping schema="" catalog="">
<class name="org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxEvent" entity-name="org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxEvent" table="HSEARCH_OUTBOX_EVENT">
<id name="id" type="long">
<generator class="org.hibernate.id.enhanced.SequenceStyleGenerator">
<param name="sequence_name">HSEARCH_OUTBOX_EVENT_GENERATOR</param>
<param name="table_name">HSEARCH_OUTBOX_EVENT_GENERATOR</param>
<param name="initial_value">1</param>
<param name="increment_size">1</param>
</generator>
</id>
<property name="entityName" type="string" length="256" nullable="false" />
<property name="entityId" type="string" length="256" nullable="false" />
<property name="entityIdHash" type="integer" index="entityIdHash" nullable="false" />
<property name="payload" type="materialized_blob" nullable="false" />
<property name="retries" type="integer" nullable="false" />
<property name="processAfter" type="Instant" index="processAfter" nullable="true" />
<property name="status" index="status" nullable="false">
<type name="org.hibernate.type.EnumType">
<param name="enumClass">org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxEvent$Status</param>
</type>
</property>
</class>
</hibernate-mapping>
08:12:39,214 (main) DEBUG OutboxPollingAgentAdditionalJaxbMappingProducer:151 - HSEARCH850014: Generated entity mapping for agents used in the outbox-polling coordination strategy: <?xml version="1.0" encoding="UTF-8"?>
<hibernate-mapping schema="" catalog="">
<class name="org.hibernate.search.mapper.orm.coordination.outboxpolling.cluster.impl.Agent" entity-name="org.hibernate.search.mapper.orm.coordination.outboxpolling.cluster.impl.Agent" table="HSEARCH_AGENT">
<id name="id">
<generator class="org.hibernate.id.enhanced.SequenceStyleGenerator">
<param name="sequence_name">HSEARCH_AGENT_GENERATOR</param>
<param name="table_name">HSEARCH_AGENT_GENERATOR</param>
<param name="initial_value">1</param>
<param name="increment_size">1</param>
</generator>
</id>
<property name="type" nullable="false">
<type name="org.hibernate.type.EnumType">
<param name="enumClass">org.hibernate.search.mapper.orm.coordination.outboxpolling.cluster.impl.AgentType</param>
</type>
</property>
<property name="name" nullable="false" />
<property name="expiration" nullable="false" />
<property name="state" nullable="false">
<type name="org.hibernate.type.EnumType">
<param name="enumClass">org.hibernate.search.mapper.orm.coordination.outboxpolling.cluster.impl.AgentState</param>
</type>
</property>
<property name="totalShardCount" nullable="true" />
<property name="assignedShardIndex" nullable="true" />
<property name="payload" nullable="true" type="materialized_blob" />
</class>
</hibernate-mapping>
08:12:39,223 (main) INFO access:48 - HHH10001501: Connection obtained from JdbcConnectionAccess [org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator$ConnectionProviderJdbcConnectionAccess@54a305fc] for (non-JTA) DDL execution was not in auto-commit mode; the Connection 'local transaction' will be committed and the Connection will be set into auto-commit mode.
08:12:39,226 (main) INFO access:48 - HHH10001501: Connection obtained from JdbcConnectionAccess [org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator$ConnectionProviderJdbcConnectionAccess@3770aa25] for (non-JTA) DDL execution was not in auto-commit mode; the Connection 'local transaction' will be committed and the Connection will be set into auto-commit mode.
08:12:40,514 (main) INFO JtaPlatformInitiator:52 - HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.JBossStandAloneJtaPlatform]
08:12:40,517 (main) DEBUG PojoMapper:178 - HSEARCH700018: Detected entity types: [HibernateOrmClassRawTypeModel[org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity], HibernateOrmClassRawTypeModel[org.hibernate.search.mapper.orm.coordination.outboxpolling.cluster.impl.Agent], HibernateOrmClassRawTypeModel[org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxEvent]], indexed types: [HibernateOrmClassRawTypeModel[org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity]], initial mapped types: [HibernateOrmClassRawTypeModel[org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity], HibernateOrmClassRawTypeModel[org.hibernate.search.mapper.orm.coordination.outboxpolling.cluster.impl.Agent], HibernateOrmClassRawTypeModel[org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxEvent], HibernateOrmClassRawTypeModel[java.lang.Object]].
08:12:40,517 (main) DEBUG PojoIndexedTypeManagerBuilder:159 - HSEARCH700017: Type manager for indexed type 'org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity':
entityName: IndexedEntity
typeIdentifier: org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity
indexManager: MappedIndexManagerImpl[implementor=StubIndexManager[IndexedEntity]]
identifierMapping: PropertyIdentifierMapping[handle=MethodHandleValueReadHandle[private java.lang.Integer org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity.id], bridgeHolder=SimpleBeanHolder[instance=DefaultIntegerBridge]]
documentRouter: org.hibernate.search.mapper.pojo.bridge.runtime.impl.NoOpDocumentRouter@12aa381f
processor:
operation: process type
objectFieldsToCreate:
nested:
- operation: apply type bridge
bridge: SimpleBeanHolder[instance=org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.PerSessionFactoryIndexingCountHelper$Bridge@5d69f24b]
- operation: process property
handle: MethodHandleValueReadHandle[private java.lang.String org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity.text]
nested:
operation: apply value bridge
bridge: SimpleBeanHolder[instance=DefaultStringBridge]
indexField: StubIndexFieldReference[text]
isEntityType: true
reindexingResolver:
operation: root
dirtyPathsTriggeringSelfReindexing: [text]
containingEntitiesResolverRoot:
operation: no op
08:12:40,518 (main) DEBUG ConfiguredAutomaticIndexingStrategy:113 - Hibernate Search event listeners activated
08:12:40,518 (main) DEBUG HibernateSearchEventListener:68 - Hibernate Search dirty checks enabled
08:12:40,518 (main) DEBUG OutboxPollingCoordinationStrategy:102 - Outbox processing will use custom agent repository provider 'org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.DisconnectionSimulatingAgentRepositoryProvider@18a0b6b4'.
08:12:40,518 (main) DEBUG OutboxPollingEventProcessor:193 - HSEARCH850005: Starting outbox event processor 'Outbox event processor'
08:12:40,520 (main) WARN CachingRegionFactory:48 - org.hibernate.testing.cache.CachingRegionFactory should be only used for testing.
08:12:40,521 (main) WARN pooling:75 - HHH10001002: Using Hibernate built-in connection pool (not for production use!)
08:12:40,521 (main) INFO pooling:119 - HHH10001005: using driver [org.postgresql.Driver] at URL [jdbc:postgresql://localhost:26257/defaultdb?sslmode=disable]
08:12:40,521 (main) INFO pooling:128 - HHH10001001: Connection properties: {password=****, user=root}
08:12:40,521 (main) INFO pooling:132 - HHH10001003: Autocommit mode: false
08:12:40,521 (main) INFO DriverManagerConnectionProviderImpl:322 - HHH000115: Hibernate connection pool size: 31 (min=1)
08:12:40,524 (main) INFO Dialect:175 - HHH000400: Using dialect: org.hibernate.dialect.CockroachDB201Dialect
08:12:40,528 (main) INFO HibernateSearchPreIntegrationService:91 - HSEARCH000034: Hibernate Search version 6.2.0-SNAPSHOT
08:12:40,529 (main) DEBUG OutboxPollingOutboxEventAdditionalJaxbMappingProducer:146 - HSEARCH850001: Generated entity mapping for outbox events used in the outbox-polling coordination strategy: <?xml version="1.0" encoding="UTF-8"?>
<hibernate-mapping schema="" catalog="">
<class name="org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxEvent" entity-name="org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxEvent" table="HSEARCH_OUTBOX_EVENT">
<id name="id" type="long">
<generator class="org.hibernate.id.enhanced.SequenceStyleGenerator">
<param name="sequence_name">HSEARCH_OUTBOX_EVENT_GENERATOR</param>
<param name="table_name">HSEARCH_OUTBOX_EVENT_GENERATOR</param>
<param name="initial_value">1</param>
<param name="increment_size">1</param>
</generator>
</id>
<property name="entityName" type="string" length="256" nullable="false" />
<property name="entityId" type="string" length="256" nullable="false" />
<property name="entityIdHash" type="integer" index="entityIdHash" nullable="false" />
<property name="payload" type="materialized_blob" nullable="false" />
<property name="retries" type="integer" nullable="false" />
<property name="processAfter" type="Instant" index="processAfter" nullable="true" />
<property name="status" index="status" nullable="false">
<type name="org.hibernate.type.EnumType">
<param name="enumClass">org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxEvent$Status</param>
</type>
</property>
</class>
</hibernate-mapping>
08:12:40,542 (Hibernate Search - Outbox event processor - 0) INFO AgentPersister:52 - Agent '#1 - Outbox event processor': registering
08:12:40,556 (main) DEBUG OutboxPollingAgentAdditionalJaxbMappingProducer:151 - HSEARCH850014: Generated entity mapping for agents used in the outbox-polling coordination strategy: <?xml version="1.0" encoding="UTF-8"?>
<hibernate-mapping schema="" catalog="">
<class name="org.hibernate.search.mapper.orm.coordination.outboxpolling.cluster.impl.Agent" entity-name="org.hibernate.search.mapper.orm.coordination.outboxpolling.cluster.impl.Agent" table="HSEARCH_AGENT">
<id name="id">
<generator class="org.hibernate.id.enhanced.SequenceStyleGenerator">
<param name="sequence_name">HSEARCH_AGENT_GENERATOR</param>
<param name="table_name">HSEARCH_AGENT_GENERATOR</param>
<param name="initial_value">1</param>
<param name="increment_size">1</param>
</generator>
</id>
<property name="type" nullable="false">
<type name="org.hibernate.type.EnumType">
<param name="enumClass">org.hibernate.search.mapper.orm.coordination.outboxpolling.cluster.impl.AgentType</param>
</type>
</property>
<property name="name" nullable="false" />
<property name="expiration" nullable="false" />
<property name="state" nullable="false">
<type name="org.hibernate.type.EnumType">
<param name="enumClass">org.hibernate.search.mapper.orm.coordination.outboxpolling.cluster.impl.AgentState</param>
</type>
</property>
<property name="totalShardCount" nullable="true" />
<property name="assignedShardIndex" nullable="true" />
<property name="payload" nullable="true" type="materialized_blob" />
</class>
</hibernate-mapping>
08:12:40,564 (main) INFO JtaPlatformInitiator:52 - HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.JBossStandAloneJtaPlatform]
08:12:40,567 (main) DEBUG PojoMapper:178 - HSEARCH700018: Detected entity types: [HibernateOrmClassRawTypeModel[org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity], HibernateOrmClassRawTypeModel[org.hibernate.search.mapper.orm.coordination.outboxpolling.cluster.impl.Agent], HibernateOrmClassRawTypeModel[org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxEvent]], indexed types: [HibernateOrmClassRawTypeModel[org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity]], initial mapped types: [HibernateOrmClassRawTypeModel[org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity], HibernateOrmClassRawTypeModel[org.hibernate.search.mapper.orm.coordination.outboxpolling.cluster.impl.Agent], HibernateOrmClassRawTypeModel[org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxEvent], HibernateOrmClassRawTypeModel[java.lang.Object]].
08:12:40,567 (main) DEBUG PojoIndexedTypeManagerBuilder:159 - HSEARCH700017: Type manager for indexed type 'org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity':
entityName: IndexedEntity
typeIdentifier: org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity
indexManager: MappedIndexManagerImpl[implementor=StubIndexManager[IndexedEntity]]
identifierMapping: PropertyIdentifierMapping[handle=MethodHandleValueReadHandle[private java.lang.Integer org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity.id], bridgeHolder=SimpleBeanHolder[instance=DefaultIntegerBridge]]
documentRouter: org.hibernate.search.mapper.pojo.bridge.runtime.impl.NoOpDocumentRouter@12aa381f
processor:
operation: process type
objectFieldsToCreate:
nested:
- operation: apply type bridge
bridge: SimpleBeanHolder[instance=org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.PerSessionFactoryIndexingCountHelper$Bridge@755766bf]
- operation: process property
handle: MethodHandleValueReadHandle[private java.lang.String org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity.text]
nested:
operation: apply value bridge
bridge: SimpleBeanHolder[instance=DefaultStringBridge]
indexField: StubIndexFieldReference[text]
isEntityType: true
reindexingResolver:
operation: root
dirtyPathsTriggeringSelfReindexing: [text]
containingEntitiesResolverRoot:
operation: no op
08:12:40,568 (main) DEBUG ConfiguredAutomaticIndexingStrategy:113 - Hibernate Search event listeners activated
08:12:40,568 (main) DEBUG HibernateSearchEventListener:68 - Hibernate Search dirty checks enabled
08:12:40,568 (main) DEBUG OutboxPollingCoordinationStrategy:102 - Outbox processing will use custom agent repository provider 'org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.DisconnectionSimulatingAgentRepositoryProvider@1db0303d'.
08:12:40,568 (main) DEBUG OutboxPollingEventProcessor:193 - HSEARCH850005: Starting outbox event processor 'Outbox event processor'
08:12:40,570 (Hibernate Search - Outbox event processor - 0) INFO OutboxPollingEventProcessorClusterLink:132 - Agent '#1 - Outbox event processor': the persisted shard assignment (null) does not match the target. Target assignment: shard 0 (total 1). Cluster: [1].
08:12:40,570 (main) WARN CachingRegionFactory:48 - org.hibernate.testing.cache.CachingRegionFactory should be only used for testing.
08:12:40,571 (main) WARN pooling:75 - HHH10001002: Using Hibernate built-in connection pool (not for production use!)
08:12:40,571 (main) INFO pooling:119 - HHH10001005: using driver [org.postgresql.Driver] at URL [jdbc:postgresql://localhost:26257/defaultdb?sslmode=disable]
08:12:40,571 (main) INFO pooling:128 - HHH10001001: Connection properties: {password=****, user=root}
08:12:40,571 (main) INFO pooling:132 - HHH10001003: Autocommit mode: false
08:12:40,571 (main) INFO DriverManagerConnectionProviderImpl:322 - HHH000115: Hibernate connection pool size: 31 (min=1)
08:12:40,572 (Hibernate Search - Outbox event processor - 0) INFO AgentPersister:81 - Agent '#1 - Outbox event processor': waiting for cluster changes. Shard assignment: shard 0 (total 1). Cluster: [1]
08:12:40,575 (main) INFO Dialect:175 - HHH000400: Using dialect: org.hibernate.dialect.CockroachDB201Dialect
08:12:40,578 (main) INFO HibernateSearchPreIntegrationService:91 - HSEARCH000034: Hibernate Search version 6.2.0-SNAPSHOT
08:12:40,580 (main) DEBUG OutboxPollingOutboxEventAdditionalJaxbMappingProducer:146 - HSEARCH850001: Generated entity mapping for outbox events used in the outbox-polling coordination strategy: <?xml version="1.0" encoding="UTF-8"?>
<hibernate-mapping schema="" catalog="">
<class name="org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxEvent" entity-name="org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxEvent" table="HSEARCH_OUTBOX_EVENT">
<id name="id" type="long">
<generator class="org.hibernate.id.enhanced.SequenceStyleGenerator">
<param name="sequence_name">HSEARCH_OUTBOX_EVENT_GENERATOR</param>
<param name="table_name">HSEARCH_OUTBOX_EVENT_GENERATOR</param>
<param name="initial_value">1</param>
<param name="increment_size">1</param>
</generator>
</id>
<property name="entityName" type="string" length="256" nullable="false" />
<property name="entityId" type="string" length="256" nullable="false" />
<property name="entityIdHash" type="integer" index="entityIdHash" nullable="false" />
<property name="payload" type="materialized_blob" nullable="false" />
<property name="retries" type="integer" nullable="false" />
<property name="processAfter" type="Instant" index="processAfter" nullable="true" />
<property name="status" index="status" nullable="false">
<type name="org.hibernate.type.EnumType">
<param name="enumClass">org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxEvent$Status</param>
</type>
</property>
</class>
</hibernate-mapping>
08:12:40,585 (Hibernate Search - Outbox event processor - 0) INFO AgentPersister:52 - Agent '#2 - Outbox event processor': registering
08:12:40,601 (Hibernate Search - Outbox event processor - 0) INFO OutboxPollingEventProcessorClusterLink:132 - Agent '#1 - Outbox event processor': the persisted shard assignment (shard 0 (total 1)) does not match the target. Target assignment: shard 0 (total 2). Cluster: [1, 2].
08:12:40,603 (Hibernate Search - Outbox event processor - 0) INFO OutboxPollingEventProcessorClusterLink:132 - Agent '#2 - Outbox event processor': the persisted shard assignment (null) does not match the target. Target assignment: shard 1 (total 2). Cluster: [1, 2].
08:12:40,604 (main) DEBUG OutboxPollingAgentAdditionalJaxbMappingProducer:151 - HSEARCH850014: Generated entity mapping for agents used in the outbox-polling coordination strategy: <?xml version="1.0" encoding="UTF-8"?>
<hibernate-mapping schema="" catalog="">
<class name="org.hibernate.search.mapper.orm.coordination.outboxpolling.cluster.impl.Agent" entity-name="org.hibernate.search.mapper.orm.coordination.outboxpolling.cluster.impl.Agent" table="HSEARCH_AGENT">
<id name="id">
<generator class="org.hibernate.id.enhanced.SequenceStyleGenerator">
<param name="sequence_name">HSEARCH_AGENT_GENERATOR</param>
<param name="table_name">HSEARCH_AGENT_GENERATOR</param>
<param name="initial_value">1</param>
<param name="increment_size">1</param>
</generator>
</id>
<property name="type" nullable="false">
<type name="org.hibernate.type.EnumType">
<param name="enumClass">org.hibernate.search.mapper.orm.coordination.outboxpolling.cluster.impl.AgentType</param>
</type>
</property>
<property name="name" nullable="false" />
<property name="expiration" nullable="false" />
<property name="state" nullable="false">
<type name="org.hibernate.type.EnumType">
<param name="enumClass">org.hibernate.search.mapper.orm.coordination.outboxpolling.cluster.impl.AgentState</param>
</type>
</property>
<property name="totalShardCount" nullable="true" />
<property name="assignedShardIndex" nullable="true" />
<property name="payload" nullable="true" type="materialized_blob" />
</class>
</hibernate-mapping>
08:12:40,604 (Hibernate Search - Outbox event processor - 0) INFO AgentPersister:81 - Agent '#2 - Outbox event processor': waiting for cluster changes. Shard assignment: shard 1 (total 2). Cluster: [1, 2]
08:12:40,612 (main) INFO JtaPlatformInitiator:52 - HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.JBossStandAloneJtaPlatform]
08:12:40,614 (main) DEBUG PojoMapper:178 - HSEARCH700018: Detected entity types: [HibernateOrmClassRawTypeModel[org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity], HibernateOrmClassRawTypeModel[org.hibernate.search.mapper.orm.coordination.outboxpolling.cluster.impl.Agent], HibernateOrmClassRawTypeModel[org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxEvent]], indexed types: [HibernateOrmClassRawTypeModel[org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity]], initial mapped types: [HibernateOrmClassRawTypeModel[org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity], HibernateOrmClassRawTypeModel[org.hibernate.search.mapper.orm.coordination.outboxpolling.cluster.impl.Agent], HibernateOrmClassRawTypeModel[org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxEvent], HibernateOrmClassRawTypeModel[java.lang.Object]].
08:12:40,615 (main) DEBUG PojoIndexedTypeManagerBuilder:159 - HSEARCH700017: Type manager for indexed type 'org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity':
entityName: IndexedEntity
typeIdentifier: org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity
indexManager: MappedIndexManagerImpl[implementor=StubIndexManager[IndexedEntity]]
identifierMapping: PropertyIdentifierMapping[handle=MethodHandleValueReadHandle[private java.lang.Integer org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity.id], bridgeHolder=SimpleBeanHolder[instance=DefaultIntegerBridge]]
documentRouter: org.hibernate.search.mapper.pojo.bridge.runtime.impl.NoOpDocumentRouter@12aa381f
processor:
operation: process type
objectFieldsToCreate:
nested:
- operation: apply type bridge
bridge: SimpleBeanHolder[instance=org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.PerSessionFactoryIndexingCountHelper$Bridge@2bb690c7]
- operation: process property
handle: MethodHandleValueReadHandle[private java.lang.String org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.OutboxPollingAutomaticIndexingDynamicShardingRebalancingIT$IndexedEntity.text]
nested:
operation: apply value bridge
bridge: SimpleBeanHolder[instance=DefaultStringBridge]
indexField: StubIndexFieldReference[text]
isEntityType: true
reindexingResolver:
operation: root
dirtyPathsTriggeringSelfReindexing: [text]
containingEntitiesResolverRoot:
operation: no op
08:12:40,615 (main) DEBUG ConfiguredAutomaticIndexingStrategy:113 - Hibernate Search event listeners activated
08:12:40,615 (main) DEBUG HibernateSearchEventListener:68 - Hibernate Search dirty checks enabled
08:12:40,615 (main) DEBUG OutboxPollingCoordinationStrategy:102 - Outbox processing will use custom agent repository provider 'org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.DisconnectionSimulatingAgentRepositoryProvider@50ec9bec'.
08:12:40,615 (main) DEBUG OutboxPollingEventProcessor:193 - HSEARCH850005: Starting outbox event processor 'Outbox event processor'
08:12:40,624 (Hibernate Search - Outbox event processor - 0) INFO OutboxPollingEventProcessorClusterLink:177 - Agent '#2 - Outbox event processor': assigning to shard 1 (total 2)
08:12:40,625 (Hibernate Search - Outbox event processor - 0) INFO OutboxPollingEventProcessorClusterLink:177 - Agent '#1 - Outbox event processor': assigning to shard 0 (total 2)
08:12:40,626 (Hibernate Search - Outbox event processor - 0) INFO AgentPersister:93 - Agent '#2 - Outbox event processor': running. Shard assignment: shard 1 (total 2). Cluster: [1, 2]
08:12:40,626 (Hibernate Search - Outbox event processor - 0) INFO AgentPersister:93 - Agent '#1 - Outbox event processor': running. Shard assignment: shard 0 (total 2). Cluster: [1, 2]
08:12:40,630 (Hibernate Search - Outbox event processor - 0) INFO AgentPersister:52 - Agent '#3 - Outbox event processor': registering
08:12:40,652 (Hibernate Search - Outbox event processor - 0) INFO OutboxPollingEventProcessorClusterLink:132 - Agent '#1 - Outbox event processor': the persisted shard assignment (shard 0 (total 2)) does not match the target. Target assignment: shard 0 (total 3). Cluster: [1, 2, 3].
08:12:40,652 (Hibernate Search - Outbox event processor - 0) INFO OutboxPollingEventProcessorClusterLink:132 - Agent '#2 - Outbox event processor': the persisted shard assignment (shard 1 (total 2)) does not match the target. Target assignment: shard 1 (total 3). Cluster: [1, 2, 3].
08:12:40,653 (Hibernate Search - Outbox event processor - 0) INFO AgentPersister:81 - Agent '#1 - Outbox event processor': waiting for cluster changes. Shard assignment: shard 0 (total 3). Cluster: [1, 2, 3]
08:12:40,653 (Hibernate Search - Outbox event processor - 0) INFO AgentPersister:81 - Agent '#2 - Outbox event processor': waiting for cluster changes. Shard assignment: shard 1 (total 3). Cluster: [1, 2, 3]
08:12:40,653 (Hibernate Search - Outbox event processor - 0) INFO OutboxPollingEventProcessorClusterLink:132 - Agent '#3 - Outbox event processor': the persisted shard assignment (null) does not match the target. Target assignment: shard 2 (total 3). Cluster: [1, 2, 3].
08:12:40,654 (Hibernate Search - Outbox event processor - 0) INFO AgentPersister:81 - Agent '#3 - Outbox event processor': waiting for cluster changes. Shard assignment: shard 2 (total 3). Cluster: [1, 2, 3]
08:12:40,674 (Hibernate Search - Outbox event processor - 0) INFO OutboxPollingEventProcessorClusterLink:177 - Agent '#1 - Outbox event processor': assigning to shard 0 (total 3)
08:12:40,675 (Hibernate Search - Outbox event processor - 0) INFO OutboxPollingEventProcessorClusterLink:177 - Agent '#3 - Outbox event processor': assigning to shard 2 (total 3)
08:12:40,675 (Hibernate Search - Outbox event processor - 0) INFO OutboxPollingEventProcessorClusterLink:177 - Agent '#2 - Outbox event processor': assigning to shard 1 (total 3)
08:12:40,676 (Hibernate Search - Outbox event processor - 0) INFO AgentPersister:93 - Agent '#1 - Outbox event processor': running. Shard assignment: shard 0 (total 3). Cluster: [1, 2, 3]
08:12:40,676 (Hibernate Search - Outbox event processor - 0) INFO AgentPersister:93 - Agent '#3 - Outbox event processor': running. Shard assignment: shard 2 (total 3). Cluster: [1, 2, 3]
08:12:40,677 (Hibernate Search - Outbox event processor - 0) INFO AgentPersister:93 - Agent '#2 - Outbox event processor': running. Shard assignment: shard 1 (total 3). Cluster: [1, 2, 3]
08:13:03,219 (awaitility-thread) DEBUG PerSessionFactoryIndexingCountHelper:129 - Count of indexing operations for each session factory for tenant ID <null>: [0, 0, 0]
08:13:03,220 (awaitility-thread) DEBUG PerSessionFactoryIndexingCountHelper:129 - Count of indexing operations for each session factory for tenant ID <null>: [0, 0, 0]
08:13:03,221 (awaitility-thread) DEBUG PerSessionFactoryIndexingCountHelper:129 - Count of indexing operations for each session factory for tenant ID <null>: [0, 0, 0]
[...]
08:13:03,373 (awaitility-thread) DEBUG PerSessionFactoryIndexingCountHelper:129 - Count of indexing operations for each session factory for tenant ID <null>: [0, 0, 0]
08:13:03,374 (awaitility-thread) DEBUG PerSessionFactoryIndexingCountHelper:129 - Count of indexing operations for each session factory for tenant ID <null>: [0, 0, 0]
08:13:03,376 (awaitility-thread) DEBUG PerSessionFactoryIndexingCountHelper:129 - Count of indexing operations for each session factory for tenant ID <null>: [0, 0, 0]
08:13:03,377 (awaitility-thread) DEBUG PerSessionFactoryIndexingCountHelper:129 - Count of indexing operations for each session factory for tenant ID <null>: [0, 0, 0]
08:13:03,378
...[truncated 2833024 chars]...
ing-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.AgentClusterLinkContextProvider.inTransaction(AgentClusterLinkContextProvider.java:41) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxPollingEventProcessor$Worker.work(OutboxPollingEventProcessor.java:231) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.engine.backend.orchestration.spi.SingletonTask$RunnableWrapper.run(SingletonTask.java:199) ~[hibernate-search-engine-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
at java.lang.Thread.run(Thread.java:833) ~[?:?]
08:13:18,416 (Hibernate Search - Outbox event processor - 0) ERROR LogFailureHandler:31 - HSEARCH000058: Exception occurred java.lang.RuntimeException: Simulating a disconnection from the database
Failing operation:
Executing task 'Outbox event processor'
java.lang.RuntimeException: Simulating a disconnection from the database
at org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.DisconnectionSimulatingAgentRepositoryProvider.create(DisconnectionSimulatingAgentRepositoryProvider.java:31) ~[test-classes/:?]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.AgentClusterLinkContext.begin(AgentClusterLinkContext.java:36) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.AgentClusterLinkContextProvider.inTransaction(AgentClusterLinkContextProvider.java:41) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxPollingEventProcessor$Worker.work(OutboxPollingEventProcessor.java:231) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.engine.backend.orchestration.spi.SingletonTask$RunnableWrapper.run(SingletonTask.java:199) ~[hibernate-search-engine-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
at java.lang.Thread.run(Thread.java:833) ~[?:?]
08:13:18,427 (Hibernate Search - Outbox event processor - 0) ERROR LogFailureHandler:31 - HSEARCH000058: Exception occurred java.lang.RuntimeException: Simulating a disconnection from the database
Failing operation:
Executing task 'Outbox event processor'
java.lang.RuntimeException: Simulating a disconnection from the database
at org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.DisconnectionSimulatingAgentRepositoryProvider.create(DisconnectionSimulatingAgentRepositoryProvider.java:31) ~[test-classes/:?]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.AgentClusterLinkContext.begin(AgentClusterLinkContext.java:36) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.AgentClusterLinkContextProvider.inTransaction(AgentClusterLinkContextProvider.java:41) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxPollingEventProcessor$Worker.work(OutboxPollingEventProcessor.java:231) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.engine.backend.orchestration.spi.SingletonTask$RunnableWrapper.run(SingletonTask.java:199) ~[hibernate-search-engine-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
at java.lang.Thread.run(Thread.java:833) ~[?:?]
08:13:18,437 (Hibernate Search - Outbox event processor - 0) ERROR LogFailureHandler:31 - HSEARCH000058: Exception occurred java.lang.RuntimeException: Simulating a disconnection from the database
Failing operation:
Executing task 'Outbox event processor'
java.lang.RuntimeException: Simulating a disconnection from the database
at org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.DisconnectionSimulatingAgentRepositoryProvider.create(DisconnectionSimulatingAgentRepositoryProvider.java:31) ~[test-classes/:?]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.AgentClusterLinkContext.begin(AgentClusterLinkContext.java:36) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.AgentClusterLinkContextProvider.inTransaction(AgentClusterLinkContextProvider.java:41) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxPollingEventProcessor$Worker.work(OutboxPollingEventProcessor.java:231) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.engine.backend.orchestration.spi.SingletonTask$RunnableWrapper.run(SingletonTask.java:199) ~[hibernate-search-engine-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
at java.lang.Thread.run(Thread.java:833) ~[?:?]
08:13:18,447 (Hibernate Search - Outbox event processor - 0) ERROR LogFailureHandler:31 - HSEARCH000058: Exception occurred java.lang.RuntimeException: Simulating a disconnection from the database
Failing operation:
Executing task 'Outbox event processor'
java.lang.RuntimeException: Simulating a disconnection from the database
at org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.DisconnectionSimulatingAgentRepositoryProvider.create(DisconnectionSimulatingAgentRepositoryProvider.java:31) ~[test-classes/:?]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.AgentClusterLinkContext.begin(AgentClusterLinkContext.java:36) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.AgentClusterLinkContextProvider.inTransaction(AgentClusterLinkContextProvider.java:41) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxPollingEventProcessor$Worker.work(OutboxPollingEventProcessor.java:231) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.engine.backend.orchestration.spi.SingletonTask$RunnableWrapper.run(SingletonTask.java:199) ~[hibernate-search-engine-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
at java.lang.Thread.run(Thread.java:833) ~[?:?]
08:13:18,448 (main) DEBUG OutboxPollingEventProcessor:208 - HSEARCH850006: Stopping outbox event processor 'Outbox event processor'
08:13:18,448 (main) ERROR RootFailureCollector:231 - HSEARCH000521: Hibernate Search encountered a failure during shutdown; continuing for now to list all problems, but the process will ultimately be aborted.
Context: Hibernate ORM mapping
Failure:
java.lang.RuntimeException: Simulating a disconnection from the database
at org.hibernate.search.integrationtest.mapper.orm.coordination.outboxpolling.automaticindexing.DisconnectionSimulatingAgentRepositoryProvider.create(DisconnectionSimulatingAgentRepositoryProvider.java:31) ~[test-classes/:?]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.AgentClusterLinkContext.begin(AgentClusterLinkContext.java:36) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.AgentClusterLinkContextProvider.inTransaction(AgentClusterLinkContextProvider.java:41) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.AgentClusterLinkContextProvider.inTransaction(AgentClusterLinkContextProvider.java:30) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxPollingEventProcessor.leaveCluster(OutboxPollingEventProcessor.java:216) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:53) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:33) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxPollingEventProcessor.stop(OutboxPollingEventProcessor.java:211) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:53) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:92) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:73) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.impl.OutboxPollingCoordinationStrategy.stop(OutboxPollingCoordinationStrategy.java:197) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:53) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.mapping.impl.HibernateOrmMapping.doStop(HibernateOrmMapping.java:207) ~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:53) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:33) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.mapping.spi.AbstractPojoMappingImplementor.stop(AbstractPojoMappingImplementor.java:72) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.engine.common.impl.SearchIntegrationImpl.lambda$close$2(SearchIntegrationImpl.java:137) ~[hibernate-search-engine-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.engine.common.impl.SearchIntegrationImpl.stopAllSafely(SearchIntegrationImpl.java:183) ~[hibernate-search-engine-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.engine.common.impl.SearchIntegrationImpl.close(SearchIntegrationImpl.java:136) ~[hibernate-search-engine-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:53) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.mapping.impl.HibernateOrmMapping.close(HibernateOrmMapping.java:159) ~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.mapping.impl.HibernateSearchContextProviderService.close(HibernateSearchContextProviderService.java:34) ~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.bootstrap.impl.HibernateOrmIntegrationBooterImpl.lambda$orchestrateBootAndShutdown$5(HibernateOrmIntegrationBooterImpl.java:160) ~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at java.util.concurrent.CompletableFuture.biAccept(CompletableFuture.java:1386) ~[?:?]
at java.util.concurrent.CompletableFuture$BiAccept.tryFire(CompletableFuture.java:1355) ~[?:?]
at java.util.concurrent.CompletableFuture$CoCompletion.tryFire(CompletableFuture.java:1219) ~[?:?]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) ~[?:?]
at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2147) ~[?:?]
at org.hibernate.search.mapper.orm.bootstrap.impl.HibernateSearchSessionFactoryObserver.sessionFactoryClosing(HibernateSearchSessionFactoryObserver.java:50) ~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.internal.SessionFactoryObserverChain.sessionFactoryClosing(SessionFactoryObserverChain.java:48) ~[hibernate-core-5.6.10.Final.jar:5.6.10.Final]
at org.hibernate.internal.SessionFactoryImpl.close(SessionFactoryImpl.java:822) ~[hibernate-core-5.6.10.Final.jar:5.6.10.Final]
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:53) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:33) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.impl.integrationtest.mapper.orm.OrmSetupHelper.close(OrmSetupHelper.java:136) ~[hibernate-search-util-internal-integrationtest-mapper-orm-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.impl.integrationtest.mapper.orm.OrmSetupHelper.close(OrmSetupHelper.java:33) ~[hibernate-search-util-internal-integrationtest-mapper-orm-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:53) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:92) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:73) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.impl.integrationtest.common.rule.MappingSetupHelper$1.evaluate(MappingSetupHelper.java:83) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.impl.integrationtest.common.TestConfigurationProvider$1.evaluate(TestConfigurationProvider.java:45) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner.run(ParentRunner.java:413) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.Suite.runChild(Suite.java:128) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.Suite.runChild(Suite.java:27) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner.run(ParentRunner.java:413) ~[junit-4.13.2.jar:4.13.2]
at org.apache.maven.surefire.junitcore.JUnitCore.run(JUnitCore.java:55) ~[surefire-junit47-3.0.0-M7.jar:3.0.0-M7]
at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:137) ~[surefire-junit47-3.0.0-M7.jar:3.0.0-M7]
at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:107) ~[surefire-junit47-3.0.0-M7.jar:3.0.0-M7]
at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:83) ~[surefire-junit47-3.0.0-M7.jar:3.0.0-M7]
at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:75) ~[surefire-junit47-3.0.0-M7.jar:3.0.0-M7]
at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:158) ~[surefire-junit47-3.0.0-M7.jar:3.0.0-M7]
at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:456) ~[surefire-booter-3.0.0-M7.jar:3.0.0-M7]
at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:169) ~[surefire-booter-3.0.0-M7.jar:3.0.0-M7]
at org.apache.maven.surefire.booter.ForkedBooter.run(ForkedBooter.java:595) ~[surefire-booter-3.0.0-M7.jar:3.0.0-M7]
at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:581) ~[surefire-booter-3.0.0-M7.jar:3.0.0-M7]
08:13:18,449 (main) ERROR HibernateOrmIntegrationBooterImpl:168 - HSEARCH800035: Unable to shut down Hibernate Search: HSEARCH000520: Hibernate Search encountered failures during shutdown. Failures:
Hibernate ORM mapping:
failures:
- Simulating a disconnection from the database
org.hibernate.search.util.common.SearchException: HSEARCH000520: Hibernate Search encountered failures during shutdown. Failures:
Hibernate ORM mapping:
failures:
- Simulating a disconnection from the database
at org.hibernate.search.engine.reporting.spi.RootFailureCollector.checkNoFailure(RootFailureCollector.java:53) ~[hibernate-search-engine-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.engine.common.impl.SearchIntegrationImpl.close(SearchIntegrationImpl.java:173) ~[hibernate-search-engine-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:53) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.mapping.impl.HibernateOrmMapping.close(HibernateOrmMapping.java:159) ~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.mapping.impl.HibernateSearchContextProviderService.close(HibernateSearchContextProviderService.java:34) ~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.bootstrap.impl.HibernateOrmIntegrationBooterImpl.lambda$orchestrateBootAndShutdown$5(HibernateOrmIntegrationBooterImpl.java:160) ~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at java.util.concurrent.CompletableFuture.biAccept(CompletableFuture.java:1386) ~[?:?]
at java.util.concurrent.CompletableFuture$BiAccept.tryFire(CompletableFuture.java:1355) ~[?:?]
at java.util.concurrent.CompletableFuture$CoCompletion.tryFire(CompletableFuture.java:1219) ~[?:?]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) ~[?:?]
at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2147) ~[?:?]
at org.hibernate.search.mapper.orm.bootstrap.impl.HibernateSearchSessionFactoryObserver.sessionFactoryClosing(HibernateSearchSessionFactoryObserver.java:50) ~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.internal.SessionFactoryObserverChain.sessionFactoryClosing(SessionFactoryObserverChain.java:48) ~[hibernate-core-5.6.10.Final.jar:5.6.10.Final]
at org.hibernate.internal.SessionFactoryImpl.close(SessionFactoryImpl.java:822) ~[hibernate-core-5.6.10.Final.jar:5.6.10.Final]
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:53) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:33) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.impl.integrationtest.mapper.orm.OrmSetupHelper.close(OrmSetupHelper.java:136) ~[hibernate-search-util-internal-integrationtest-mapper-orm-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.impl.integrationtest.mapper.orm.OrmSetupHelper.close(OrmSetupHelper.java:33) ~[hibernate-search-util-internal-integrationtest-mapper-orm-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.common.impl.AbstractCloser.push(AbstractCloser.java:53) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:92) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.common.impl.AbstractCloser.pushAll(AbstractCloser.java:73) ~[hibernate-search-util-common-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.util.impl.integrationtest.common.rule.MappingSetupHelper$1.evaluate(MappingSetupHelper.java:83) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.impl.integrationtest.common.TestConfigurationProvider$1.evaluate(TestConfigurationProvider.java:45) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner.run(ParentRunner.java:413) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.Suite.runChild(Suite.java:128) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.Suite.runChild(Suite.java:27) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306) ~[junit-4.13.2.jar:4.13.2]
at org.junit.runners.ParentRunner.run(ParentRunner.java:413) ~[junit-4.13.2.jar:4.13.2]
at org.apache.maven.surefire.junitcore.JUnitCore.run(JUnitCore.java:55) ~[surefire-junit47-3.0.0-M7.jar:3.0.0-M7]
at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:137) ~[surefire-junit47-3.0.0-M7.jar:3.0.0-M7]
at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:107) ~[surefire-junit47-3.0.0-M7.jar:3.0.0-M7]
at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:83) ~[surefire-junit47-3.0.0-M7.jar:3.0.0-M7]
at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:75) ~[surefire-junit47-3.0.0-M7.jar:3.0.0-M7]
at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:158) ~[surefire-junit47-3.0.0-M7.jar:3.0.0-M7]
at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:456) ~[surefire-booter-3.0.0-M7.jar:3.0.0-M7]
at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:169) ~[surefire-booter-3.0.0-M7.jar:3.0.0-M7]
at org.apache.maven.surefire.booter.ForkedBooter.run(ForkedBooter.java:595) ~[surefire-booter-3.0.0-M7.jar:3.0.0-M7]
at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:581) ~[surefire-booter-3.0.0-M7.jar:3.0.0-M7]
08:13:18,449 (main) INFO pooling:550 - HHH10001008: Cleaning up connection pool [jdbc:postgresql://localhost:26257/defaultdb?sslmode=disable]
08:13:18,453 (Hibernate Search - Outbox event processor - 0) ERROR LogFailureHandler:36 - HSEARCH000058: Exception occurred java.lang.AssertionError: No call expected, but got: creation of a ADD_OR_UPDATE work on document 'IndexedEntity#2907'
Failing operation:
Processing an outbox event.
Entities that could not be indexed correctly:
IndexedEntity#2907 IndexedEntity#2908 IndexedEntity#2909 IndexedEntity#2911 IndexedEntity#2913
java.lang.AssertionError: No call expected, but got: creation of a ADD_OR_UPDATE work on document 'IndexedEntity#2907'
at org.junit.Assert.fail(Assert.java:89) ~[junit-4.13.2.jar:4.13.2]
at org.hibernate.search.util.impl.integrationtest.common.rule.VerifyingStubBackendBehavior.lambda$strictNoExpectationsBehavior$25(VerifyingStubBackendBehavior.java:429) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.impl.integrationtest.common.rule.CallQueue.tryVerify(CallQueue.java:114) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.impl.integrationtest.common.rule.CallQueue.verify(CallQueue.java:68) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.impl.integrationtest.common.rule.VerifyingStubBackendBehavior.createDocumentWork(VerifyingStubBackendBehavior.java:329) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.impl.integrationtest.common.stub.backend.index.impl.StubIndexIndexingPlan.addWork(StubIndexIndexingPlan.java:133) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.impl.integrationtest.common.stub.backend.index.impl.StubIndexIndexingPlan.addOrUpdate(StubIndexIndexingPlan.java:74) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.mapper.pojo.work.impl.PojoTypeIndexingPlanIndexDelegate.addOrUpdate(PojoTypeIndexingPlanIndexDelegate.java:79) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.PojoTypeIndexingPlanIndexOrEventQueueDelegate.addOrUpdate(PojoTypeIndexingPlanIndexOrEventQueueDelegate.java:79) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.AbstractPojoTypeIndexingPlan$AbstractEntityState.delegateAddOrUpdate(AbstractPojoTypeIndexingPlan.java:383) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.AbstractPojoTypeIndexingPlan$AbstractEntityState.sendCommandsToDelegate(AbstractPojoTypeIndexingPlan.java:322) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.AbstractPojoTypeIndexingPlan.process(AbstractPojoTypeIndexingPlan.java:106) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.PojoIndexingPlanImpl.process(PojoIndexingPlanImpl.java:135) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.PojoIndexingPlanImpl.executeAndReport(PojoIndexingPlanImpl.java:150) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.PojoIndexingQueueEventProcessingPlanImpl.executeAndReport(PojoIndexingQueueEventProcessingPlanImpl.java:51) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.automaticindexing.impl.AutomaticIndexingQueueEventProcessingPlanImpl.executeAndReport(AutomaticIndexingQueueEventProcessingPlanImpl.java:36) ~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxEventProcessingPlan.processEvents(OutboxEventProcessingPlan.java:46) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxPollingEventProcessor$Worker.lambda$work$0(OutboxPollingEventProcessor.java:269) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.common.spi.TransactionHelper.inTransaction(TransactionHelper.java:54) ~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxPollingEventProcessor$Worker.work(OutboxPollingEventProcessor.java:244) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.engine.backend.orchestration.spi.SingletonTask$RunnableWrapper.run(SingletonTask.java:199) ~[hibernate-search-engine-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
at java.lang.Thread.run(Thread.java:833) ~[?:?]
08:13:18,453 (Hibernate Search - Outbox event processor - 0) ERROR LogFailureHandler:36 - HSEARCH000058: Exception occurred java.lang.AssertionError: No call expected, but got: creation of a ADD_OR_UPDATE work on document 'IndexedEntity#2930'
Failing operation:
Processing an outbox event.
Entities that could not be indexed correctly:
IndexedEntity#2930 IndexedEntity#2934 IndexedEntity#2935 IndexedEntity#2937 IndexedEntity#2941
java.lang.AssertionError: No call expected, but got: creation of a ADD_OR_UPDATE work on document 'IndexedEntity#2930'
at org.junit.Assert.fail(Assert.java:89) ~[junit-4.13.2.jar:4.13.2]
at org.hibernate.search.util.impl.integrationtest.common.rule.VerifyingStubBackendBehavior.lambda$strictNoExpectationsBehavior$25(VerifyingStubBackendBehavior.java:429) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.impl.integrationtest.common.rule.CallQueue.tryVerify(CallQueue.java:114) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.impl.integrationtest.common.rule.CallQueue.verify(CallQueue.java:68) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.impl.integrationtest.common.rule.VerifyingStubBackendBehavior.createDocumentWork(VerifyingStubBackendBehavior.java:329) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.impl.integrationtest.common.stub.backend.index.impl.StubIndexIndexingPlan.addWork(StubIndexIndexingPlan.java:133) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.impl.integrationtest.common.stub.backend.index.impl.StubIndexIndexingPlan.addOrUpdate(StubIndexIndexingPlan.java:74) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.mapper.pojo.work.impl.PojoTypeIndexingPlanIndexDelegate.addOrUpdate(PojoTypeIndexingPlanIndexDelegate.java:79) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.PojoTypeIndexingPlanIndexOrEventQueueDelegate.addOrUpdate(PojoTypeIndexingPlanIndexOrEventQueueDelegate.java:79) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.AbstractPojoTypeIndexingPlan$AbstractEntityState.delegateAddOrUpdate(AbstractPojoTypeIndexingPlan.java:383) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.AbstractPojoTypeIndexingPlan$AbstractEntityState.sendCommandsToDelegate(AbstractPojoTypeIndexingPlan.java:322) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.AbstractPojoTypeIndexingPlan.process(AbstractPojoTypeIndexingPlan.java:106) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.PojoIndexingPlanImpl.process(PojoIndexingPlanImpl.java:135) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.PojoIndexingPlanImpl.executeAndReport(PojoIndexingPlanImpl.java:150) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.PojoIndexingQueueEventProcessingPlanImpl.executeAndReport(PojoIndexingQueueEventProcessingPlanImpl.java:51) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.automaticindexing.impl.AutomaticIndexingQueueEventProcessingPlanImpl.executeAndReport(AutomaticIndexingQueueEventProcessingPlanImpl.java:36) ~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxEventProcessingPlan.processEvents(OutboxEventProcessingPlan.java:46) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxPollingEventProcessor$Worker.lambda$work$0(OutboxPollingEventProcessor.java:269) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.common.spi.TransactionHelper.inTransaction(TransactionHelper.java:54) ~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxPollingEventProcessor$Worker.work(OutboxPollingEventProcessor.java:244) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.engine.backend.orchestration.spi.SingletonTask$RunnableWrapper.run(SingletonTask.java:199) ~[hibernate-search-engine-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
at java.lang.Thread.run(Thread.java:833) ~[?:?]
08:13:18,454 (Hibernate Search - Outbox event processor - 0) WARN OutboxEventUpdater:88 - HSEARCH850004: Automatic indexing failed for event #2931 on entity of type 'IndexedEntity' with ID '2930'. Attempts so far: 1. The event will be reprocessed after the moment: 2022-08-26T08:13:48.454801044Z.
08:13:18,454 (Hibernate Search - Outbox event processor - 0) WARN OutboxEventUpdater:88 - HSEARCH850004: Automatic indexing failed for event #2908 on entity of type 'IndexedEntity' with ID '2907'. Attempts so far: 1. The event will be reprocessed after the moment: 2022-08-26T08:13:48.454868415Z.
08:13:18,454 (Hibernate Search - Outbox event processor - 0) WARN OutboxEventUpdater:88 - HSEARCH850004: Automatic indexing failed for event #2909 on entity of type 'IndexedEntity' with ID '2908'. Attempts so far: 1. The event will be reprocessed after the moment: 2022-08-26T08:13:48.454926756Z.
08:13:18,454 (Hibernate Search - Outbox event processor - 0) WARN OutboxEventUpdater:88 - HSEARCH850004: Automatic indexing failed for event #2910 on entity of type 'IndexedEntity' with ID '2909'. Attempts so far: 1. The event will be reprocessed after the moment: 2022-08-26T08:13:48.454958517Z.
08:13:18,454 (Hibernate Search - Outbox event processor - 0) WARN OutboxEventUpdater:88 - HSEARCH850004: Automatic indexing failed for event #2935 on entity of type 'IndexedEntity' with ID '2934'. Attempts so far: 1. The event will be reprocessed after the moment: 2022-08-26T08:13:48.454924106Z.
08:13:18,455 (Hibernate Search - Outbox event processor - 0) WARN OutboxEventUpdater:88 - HSEARCH850004: Automatic indexing failed for event #2912 on entity of type 'IndexedEntity' with ID '2911'. Attempts so far: 1. The event will be reprocessed after the moment: 2022-08-26T08:13:48.454985497Z.
08:13:18,455 (Hibernate Search - Outbox event processor - 0) WARN OutboxEventUpdater:88 - HSEARCH850004: Automatic indexing failed for event #2914 on entity of type 'IndexedEntity' with ID '2913'. Attempts so far: 1. The event will be reprocessed after the moment: 2022-08-26T08:13:48.455011207Z.
08:13:18,455 (Hibernate Search - Outbox event processor - 0) WARN OutboxEventUpdater:88 - HSEARCH850004: Automatic indexing failed for event #2936 on entity of type 'IndexedEntity' with ID '2935'. Attempts so far: 1. The event will be reprocessed after the moment: 2022-08-26T08:13:48.455004467Z.
08:13:18,455 (Hibernate Search - Outbox event processor - 0) WARN OutboxEventUpdater:88 - HSEARCH850004: Automatic indexing failed for event #2938 on entity of type 'IndexedEntity' with ID '2937'. Attempts so far: 1. The event will be reprocessed after the moment: 2022-08-26T08:13:48.455038518Z.
08:13:18,455 (Hibernate Search - Outbox event processor - 0) WARN OutboxEventUpdater:88 - HSEARCH850004: Automatic indexing failed for event #2942 on entity of type 'IndexedEntity' with ID '2941'. Attempts so far: 1. The event will be reprocessed after the moment: 2022-08-26T08:13:48.455064748Z.
08:13:18,470 (main) DEBUG OutboxPollingEventProcessor:208 - HSEARCH850006: Stopping outbox event processor 'Outbox event processor'
08:13:18,470 (main) INFO AgentPersister:60 - Agent '#2 - Outbox event processor': leaving cluster
08:13:18,484 (Hibernate Search - Outbox event processor - 0) ERROR LogFailureHandler:36 - HSEARCH000058: Exception occurred java.lang.AssertionError: No call expected, but got: creation of a ADD_OR_UPDATE work on document 'IndexedEntity#2943'
Failing operation:
Processing an outbox event.
Entities that could not be indexed correctly:
IndexedEntity#2943 IndexedEntity#2945 IndexedEntity#2950 IndexedEntity#2951 IndexedEntity#2954
java.lang.AssertionError: No call expected, but got: creation of a ADD_OR_UPDATE work on document 'IndexedEntity#2943'
at org.junit.Assert.fail(Assert.java:89) ~[junit-4.13.2.jar:4.13.2]
at org.hibernate.search.util.impl.integrationtest.common.rule.VerifyingStubBackendBehavior.lambda$strictNoExpectationsBehavior$25(VerifyingStubBackendBehavior.java:429) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.impl.integrationtest.common.rule.CallQueue.tryVerify(CallQueue.java:114) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.impl.integrationtest.common.rule.CallQueue.verify(CallQueue.java:68) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.impl.integrationtest.common.rule.VerifyingStubBackendBehavior.createDocumentWork(VerifyingStubBackendBehavior.java:329) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.impl.integrationtest.common.stub.backend.index.impl.StubIndexIndexingPlan.addWork(StubIndexIndexingPlan.java:133) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.util.impl.integrationtest.common.stub.backend.index.impl.StubIndexIndexingPlan.addOrUpdate(StubIndexIndexingPlan.java:74) ~[hibernate-search-util-internal-integrationtest-common-6.2.0-SNAPSHOT.jar:?]
at org.hibernate.search.mapper.pojo.work.impl.PojoTypeIndexingPlanIndexDelegate.addOrUpdate(PojoTypeIndexingPlanIndexDelegate.java:79) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.PojoTypeIndexingPlanIndexOrEventQueueDelegate.addOrUpdate(PojoTypeIndexingPlanIndexOrEventQueueDelegate.java:79) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.AbstractPojoTypeIndexingPlan$AbstractEntityState.delegateAddOrUpdate(AbstractPojoTypeIndexingPlan.java:383) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.AbstractPojoTypeIndexingPlan$AbstractEntityState.sendCommandsToDelegate(AbstractPojoTypeIndexingPlan.java:322) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.AbstractPojoTypeIndexingPlan.process(AbstractPojoTypeIndexingPlan.java:106) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.PojoIndexingPlanImpl.process(PojoIndexingPlanImpl.java:135) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.PojoIndexingPlanImpl.executeAndReport(PojoIndexingPlanImpl.java:150) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.pojo.work.impl.PojoIndexingQueueEventProcessingPlanImpl.executeAndReport(PojoIndexingQueueEventProcessingPlanImpl.java:51) ~[hibernate-search-mapper-pojo-base-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.automaticindexing.impl.AutomaticIndexingQueueEventProcessingPlanImpl.executeAndReport(AutomaticIndexingQueueEventProcessingPlanImpl.java:36) ~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxEventProcessingPlan.processEvents(OutboxEventProcessingPlan.java:46) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxPollingEventProcessor$Worker.lambda$work$0(OutboxPollingEventProcessor.java:269) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.common.spi.TransactionHelper.inTransaction(TransactionHelper.java:54) ~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxPollingEventProcessor$Worker.work(OutboxPollingEventProcessor.java:244) ~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at org.hibernate.search.engine.backend.orchestration.spi.SingletonTask$RunnableWrapper.run(SingletonTask.java:199) ~[hibernate-search-engine-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
at java.lang.Thread.run(Thread.java:833) ~[?:?]
08:13:18,485 (main) INFO pooling:550 - HHH10001008: Cleaning up connection pool [jdbc:postgresql://localhost:26257/defaultdb?sslmode=disable]
08:13:18,486 (Hibernate Search - Outbox event processor - 0) WARN OutboxEventUpdater:88 - HSEARCH850004: Automatic indexing failed for event #2944 on entity of type 'IndexedEntity' with ID '2943'. Attempts so far: 1. The event will be reprocessed after the moment: 2022-08-26T08:13:48.486694153Z.
08:13:18,486 (Hibernate Search - Outbox event processor - 0) WARN OutboxEventUpdater:88 - HSEARCH850004: Automatic indexing failed for event #2946 on entity of type 'IndexedEntity' with ID '2945'. Attempts so far: 1. The event will be reprocessed after the moment: 2022-08-26T08:13:48.486767034Z.
08:13:18,486 (Hibernate Search - Outbox event processor - 0) WARN OutboxEventUpdater:88 - HSEARCH850004: Automatic indexing failed for event #2951 on entity of type 'IndexedEntity' with ID '2950'. Attempts so far: 1. The event will be reprocessed after the moment: 2022-08-26T08:13:48.486788535Z.
08:13:18,486 (Hibernate Search - Outbox event processor - 0) WARN OutboxEventUpdater:88 - HSEARCH850004: Automatic indexing failed for event #2952 on entity of type 'IndexedEntity' with ID '2951'. Attempts so far: 1. The event will be reprocessed after the moment: 2022-08-26T08:13:48.486804375Z.
08:13:18,486 (Hibernate Search - Outbox event processor - 0) WARN OutboxEventUpdater:88 - HSEARCH850004: Automatic indexing failed for event #2955 on entity of type 'IndexedEntity' with ID '2954'. Attempts so far: 1. The event will be reprocessed after the moment: 2022-08-26T08:13:48.486818535Z.
08:13:18,502 (Hibernate Search - Outbox event processor - 0) INFO OutboxPollingEventProcessorClusterLink:132 - Agent '#1 - Outbox event processor': the persisted shard assignment (shard 0 (total 2)) does not match the target. Target assignment: shard 0 (total 1). Cluster: [1].
08:13:18,503 (Hibernate Search - Outbox event processor - 0) INFO AgentPersister:81 - Agent '#1 - Outbox event processor': waiting for cluster changes. Shard assignment: shard 0 (total 1). Cluster: [1]
08:13:18,512 (main) DEBUG OutboxPollingEventProcessor:208 - HSEARCH850006: Stopping outbox event processor 'Outbox event processor'
08:13:18,513 (main) INFO AgentPersister:60 - Agent '#1 - Outbox event processor': leaving cluster
08:13:18,530 (main) INFO SchemaDropperImpl$DelayedDropActionImpl:538 - HHH000477: Starting delayed evictData of schema as part of SessionFactory shut-down'
08:13:18,530 (main) INFO access:48 - HHH10001501: Connection obtained from JdbcConnectionAccess [org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator$ConnectionProviderJdbcConnectionAccess@226c1f72] for (non-JTA) DDL execution was not in auto-commit mode; the Connection 'local transaction' will be committed and the Connection will be set into auto-commit mode.
08:13:19,156 (main) INFO pooling:550 - HHH10001008: Cleaning up connection pool [jdbc:postgresql://localhost:26257/defaultdb?sslmode=disable]
( https://hibernate.atlassian.net/browse/HSEARCH-4687#add-comment?atlOrigin... ) Add Comment ( https://hibernate.atlassian.net/browse/HSEARCH-4687#add-comment?atlOrigin... )
Get Jira notifications on your phone! Download the Jira Cloud app for Android ( https://play.google.com/store/apps/details?id=com.atlassian.android.jira.... ) or iOS ( https://itunes.apple.com/app/apple-store/id1006972087?pt=696495&ct=EmailN... ) This message was sent by Atlassian Jira (v1001.0.0-SNAPSHOT#100206- sha1:4ed3dc7 )
2 years, 4 months
[JIRA] (HSEARCH-4684) Fix tests starting before postgresql/cockroachdb containers are ready on CI
by Yoann Rodière (JIRA)
Yoann Rodière ( https://hibernate.atlassian.net/secure/ViewProfile.jspa?accountId=557058%... ) *commented* on HSEARCH-4684 ( https://hibernate.atlassian.net/browse/HSEARCH-4684?atlOrigin=eyJpIjoiZmQ... )
Re: Fix tests starting before postgresql/cockroachdb containers are ready on CI ( https://hibernate.atlassian.net/browse/HSEARCH-4684?atlOrigin=eyJpIjoiZmQ... )
Weirdly, it seems postgres will display “database system is ready to accept connections“ in logs twice on startup:
The files belonging to this database system will be owned by user "postgres".
This user must also own the server process.
The database cluster will be initialized with locale "en_US.utf8".
The default database encoding has accordingly been set to "UTF8".
The default text search configuration will be set to "english".
Data page checksums are disabled.
fixing permissions on existing directory /var/lib/postgresql/data ... ok
creating subdirectories ... ok
selecting dynamic shared memory implementation ... posix
selecting default max_connections ... 100
selecting default shared_buffers ... 128MB
selecting default time zone ... Etc/UTC
creating configuration files ... ok
running bootstrap script ... ok
performing post-bootstrap initialization ... ok
syncing data to disk ... ok
initdb: warning: enabling "trust" authentication for local connections
You can change this by editing pg_hba.conf or using the option -A, or
--auth-local and --auth-host, the next time you run initdb.
Success. You can now start the database server using:
pg_ctl -D /var/lib/postgresql/data -l logfile start
waiting for server to start....2022-08-25 16:50:05.411 UTC [47] LOG: starting PostgreSQL 13.1 (Debian 13.1-1.pgdg100+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 8.3.0-6) 8.3.0, 64-bit
2022-08-25 16:50:05.422 UTC [47] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2022-08-25 16:50:05.443 UTC [48] LOG: database system was shut down at 2022-08-25 16:50:05 UTC
2022-08-25 16:50:05.454 UTC [47] LOG: database system is ready to accept connections
done
server started
CREATE DATABASE
/usr/local/bin/docker-entrypoint.sh: ignoring /docker-entrypoint-initdb.d/*
2022-08-25 16:50:05.824 UTC [47] LOG: received fast shutdown request
waiting for server to shut down....2022-08-25 16:50:05.831 UTC [47] LOG: aborting any active transactions
2022-08-25 16:50:05.835 UTC [47] LOG: background worker "logical replication launcher" (PID 54) exited with exit code 1
2022-08-25 16:50:05.836 UTC [49] LOG: shutting down
2022-08-25 16:50:05.886 UTC [47] LOG: database system is shut down
done
server stopped
PostgreSQL init process complete; ready for start up.
2022-08-25 16:50:05.976 UTC [1] LOG: starting PostgreSQL 13.1 (Debian 13.1-1.pgdg100+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 8.3.0-6) 8.3.0, 64-bit
2022-08-25 16:50:05.977 UTC [1] LOG: listening on IPv4 address "0.0.0.0", port 5432
2022-08-25 16:50:05.977 UTC [1] LOG: listening on IPv6 address "::", port 5432
2022-08-25 16:50:05.990 UTC [1] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2022-08-25 16:50:06.008 UTC [75] LOG: database system was shut down at 2022-08-25 16:50:05 UTC
2022-08-25 16:50:06.022 UTC [1] LOG: database system is ready to accept connections
Since it will restart before the first and second time it logs that sentence, we can’t really rely on logs to determine if postgres is ready…
( https://hibernate.atlassian.net/browse/HSEARCH-4684#add-comment?atlOrigin... ) Add Comment ( https://hibernate.atlassian.net/browse/HSEARCH-4684#add-comment?atlOrigin... )
Get Jira notifications on your phone! Download the Jira Cloud app for Android ( https://play.google.com/store/apps/details?id=com.atlassian.android.jira.... ) or iOS ( https://itunes.apple.com/app/apple-store/id1006972087?pt=696495&ct=EmailN... ) This message was sent by Atlassian Jira (v1001.0.0-SNAPSHOT#100206- sha1:9fe2ddf )
2 years, 4 months