Infinite indexing loop for filebased taxonomies and collected datasets

johannes-darms commented 9 months ago

This issue is unique

[X] I have used the search tool and did not find an issue describing my bug.

Version information

SNAPSHOT and 5.2.2

Expected behavior

First, I import a taxonomy via the new file import tool. Second, I publish a collected dataset, that also uses the new file import tool. I expect the index process to finish at some point.

Actual behavior

The index process never stops and loops forever. Heres one iteration of the log:

2023-09-28 14:20:33.744  WARN 69 --- [ack][bulk][T#6]] org.elasticsearch.action.bulk            : [Yukon Jack] unexpected error during the primary phase for action [indices:data/write/bulk[s]], request [BulkShardRequest to [term] containing [3] requests]

org.elasticsearch.index.IndexNotFoundException: no such index
    at org.elasticsearch.cluster.routing.RoutingTable.shardRoutingTable(RoutingTable.java:108)
    at org.elasticsearch.action.support.replication.TransportReplicationAction$ReroutePhase.doRun(TransportReplicationAction.java:470)
    at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)
    at org.elasticsearch.action.support.replication.TransportReplicationAction$ReroutePhase$2.onNewClusterState(TransportReplicationAction.java:565)
    at org.elasticsearch.cluster.ClusterStateObserver.waitForNextChange(ClusterStateObserver.java:146)
    at org.elasticsearch.cluster.ClusterStateObserver.waitForNextChange(ClusterStateObserver.java:98)
    at org.elasticsearch.cluster.ClusterStateObserver.waitForNextChange(ClusterStateObserver.java:90)
    at org.elasticsearch.action.support.replication.TransportReplicationAction$ReroutePhase.retry(TransportReplicationAction.java:562)
    at org.elasticsearch.action.support.replication.TransportReplicationAction$ReroutePhase$1.handleException(TransportReplicationAction.java:543)
    at org.elasticsearch.transport.TransportService$DirectResponseChannel.processException(TransportService.java:874)
    at org.elasticsearch.transport.TransportService$DirectResponseChannel.sendResponse(TransportService.java:852)
    at org.elasticsearch.transport.DelegatingTransportChannel.sendResponse(DelegatingTransportChannel.java:68)
    at org.elasticsearch.transport.RequestHandlerRegistry$TransportChannelWrapper.sendResponse(RequestHandlerRegistry.java:152)
    at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryPhase.finishAsFailed(TransportReplicationAction.java:748)
    at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryPhase.finishBecauseUnavailable(TransportReplicationAction.java:758)
    at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryPhase.doRun(TransportReplicationAction.java:651)
    at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)
    at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:287)
    at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:279)
    at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:77)
    at org.elasticsearch.transport.TransportService$4.doRun(TransportService.java:378)
    at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:750)

2023-09-28 14:20:36.880 DEBUG 69 --- [      task-1691] org.obiba.es.mica.ESIndexer              : Indexing all indexables for dexables for indexName [term] persistableObjectNumber [2]
bles for indexName [vocabulary] persistableObjectNumber [9]
2023-09-28 14:20:37.334 DEBUG 69 --- [      task-1685] org.obiba.es.mica.ESIndexer              : Indexing all indexables for indexName [term] persistableObjectNumber [3]
2023-09-28 14:20:37.334  WARN 69 --- [ack][bulk][T#8]] org.elasticsearch.action.bulk            : [Yukon Jack] unexpected error during the primary phase for action [indices:data/write/bulk[s]], request [BulkShardRequest to [vocabulary] containing [2] requests]

Reproduction steps

First, I import a taxonomy via the new file import tool. Second, I publish a collected dataset, that also uses the new file import tool. The logs show an index creation+indexing followed by an IndexNotFoundException, which triggers a re-indexing. This loops forever...

Operating System (OS)

Linux

Browser

FireFox, Opera

Contact info

No response

kazoompa commented 9 months ago

Can you provide sample files of your Taxonomy and Dataset file? I just tried your scenario and did not have any issues. I was wondering maybe there is something different with regards to your file format.

johannes-darms commented 9 months ago

I can reproduce the error with this file /collected-dataset/tracking_60min_r1/CLSA.Tracking_60min_R1-dictionary.xlsx, stored in this testing instance (https://mica-play.obiba.org/admin#/collected-dataset/tracking_60min_r1) and this taxonomy file https://github.com/maelstrom-research/maelstrom-taxonomies/blob/master/AreaOfInformation.yml

I can correctly parse the Variable file with the magma source code. I'm quite sure the issue is related to the mica source code. However, I use the docker-compose file with the embedded elasaticsearch.

johannes-darms commented 9 months ago

I just checked again I can reproduce the error without importing any collected-dataset. Just uploading the taxonomy is sufficient.

ymarcon commented 9 months ago

I also got the issue

2023-09-29 12:15:09.499  INFO 3364250 --- [        task-35] org.obiba.mica.taxonomy.TaxonomyIndexer  : All taxonomies were updated
2023-09-29 12:15:09.503  INFO 3364250 --- [pdateTask][T#1]] org.elasticsearch.cluster.metadata       : [Mekano] [taxonomy] creating index, cause [api], templates [], shards [5]/[1], mappings []
2023-09-29 12:15:09.530 ERROR 3364250 --- [        task-35] .a.i.SimpleAsyncUncaughtExceptionHandler : Unexpected exception occurred invoking async method: public void org.obiba.mica.taxonomy.TaxonomyIndexer.taxonomiesUpdated(org.obiba.mica.micaConfig.event.TaxonomiesUpdatedEvent)

org.elasticsearch.index.IndexNotFoundException: no such index
    at org.elasticsearch.cluster.metadata.MetaDataDeleteIndexService$1.execute(MetaDataDeleteIndexService.java:91)
    at org.elasticsearch.cluster.ClusterStateUpdateTask.execute(ClusterStateUpdateTask.java:45)
    at org.elasticsearch.cluster.service.InternalClusterService.runTasksForExecutor(InternalClusterService.java:480)
    at org.elasticsearch.cluster.service.InternalClusterService$UpdateTask.run(InternalClusterService.java:784)
    at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.runAndClean(PrioritizedEsThreadPoolExecutor.java:231)
    at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.run(PrioritizedEsThreadPoolExecutor.java:194)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Wo

johannes-darms commented 9 months ago

I'm not sure if there are to many TaxonomiesUpdatedEvent or the issues is within the TaxonomyIndexer.

2023-09-29 09:43:55.593  INFO 70 --- [        task-27] org.obiba.mica.taxonomy.TaxonomyIndexer  : All taxonomies were updated
2023-09-29 09:43:55.602 DEBUG 70 --- [        task-31] org.obiba.es.mica.ESIndexer              : Indexing for indexName [taxonomy] indexableObject [org.obiba.mica.taxonomy.TaxonomyIndexable@5c90f319]
2023-09-29 09:43:55.602  INFO 70 --- [        task-31] org.obiba.es.mica.ESIndexer              : Creating index taxonomy

2023-09-29 09:43:52.110  INFO 70 --- [        task-29] org.obiba.es.mica.ESIndexer              : Creating index taxonomy
2023-09-29 09:43:52.110 ERROR 70 --- [        task-22] .a.i.SimpleAsyncUncaughtExceptionHandler : Unexpected exception occurred invoking async method: public void org.obiba.mica.taxonomy.TaxonomyIndexer.taxonomiesUpdated(org.obiba.mica.micaConfig.event.TaxonomiesUpdatedEvent)

org.elasticsearch.index.IndexNotFoundException: no such index
        at org.elasticsearch.cluster.metadata.IndexNameExpressionResolver$WildcardExpressionResolver.resolve(IndexNameExpressionResolver.java:581)
        at org.elasticsearch.cluster.metadata.IndexNameExpressionResolver.concreteIndices(IndexNameExpressionResolver.java:133)
        at org.elasticsearch.cluster.metadata.IndexNameExpressionResolver.concreteIndices(IndexNameExpressionResolver.java:77)
        at org.elasticsearch.action.admin.indices.mapping.put.TransportPutMappingAction.checkBlock(TransportPutMappingAction.java:66)
        at org.elasticsearch.action.admin.indices.mapping.put.TransportPutMappingAction.checkBlock(TransportPutMappingAction.java:41)
        at org.elasticsearch.action.support.master.TransportMasterNodeAction$AsyncSingleAction.doStart(TransportMasterNodeAction.java:156)
        at org.elasticsearch.action.support.master.TransportMasterNodeAction$AsyncSingleAction.start(TransportMasterNodeAction.java:148)
        at org.elasticsearch.action.support.master.TransportMasterNodeAction.doExecute(TransportMasterNodeAction.java:115)
        at org.elasticsearch.action.support.master.TransportMasterNodeAction.doExecute(TransportMasterNodeAction.java:50)
        at org.elasticsearch.action.support.TransportAction.execute(TransportAction.java:137)
        at org.elasticsearch.action.support.TransportAction.execute(TransportAction.java:85)
        at org.elasticsearch.client.node.NodeClient.doExecute(NodeClient.java:58)
        at org.elasticsearch.client.support.AbstractClient.execute(AbstractClient.java:359)
        at org.elasticsearch.client.support.AbstractClient$IndicesAdmin.execute(AbstractClient.java:1226)
        at org.elasticsearch.action.ActionRequestBuilder.execute(ActionRequestBuilder.java:86)
        at org.elasticsearch.action.ActionRequestBuilder.execute(ActionRequestBuilder.java:56)
        at org.obiba.es.mica.mapping.TaxonomyIndexConfiguration.onIndexCreated(TaxonomyIndexConfiguration.java:57)
        at org.obiba.es.mica.ESIndexer.lambda$createIndexIfNeeded$2(ESIndexer.java:250)
        at java.lang.Iterable.forEach(Iterable.java:75)
        at org.obiba.es.mica.ESIndexer.createIndexIfNeeded(ESIndexer.java:250)
        at org.obiba.es.mica.ESIndexer.index(ESIndexer.java:79)
        at org.obiba.es.mica.ESIndexer.index(ESIndexer.java:73)
        at org.obiba.mica.search.SearchEngineIndexer.index(SearchEngineIndexer.java:46)
        at org.obiba.mica.taxonomy.TaxonomyIndexer.lambda$index$5(TaxonomyIndexer.java:119)
        at java.lang.Iterable.forEach(Iterable.java:75)
        at org.obiba.mica.taxonomy.TaxonomyIndexer.index(TaxonomyIndexer.java:118)
        at org.obiba.mica.taxonomy.TaxonomyIndexer.taxonomiesUpdated(TaxonomyIndexer.java:75)
        at org.obiba.mica.taxonomy.TaxonomyIndexer$$FastClassBySpringCGLIB$$1c4955a2.invoke(<generated>)
        at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:793)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
        at org.springframework.aop.interceptor.AsyncExecutionInterceptor.lambda$invoke$0(AsyncExecutionInterceptor.java:115)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:750)

kazoompa commented 9 months ago

There is a workaround for now:

Stop Mica
Edit mica-taxonomy.yml in $MICA_HOME/config folder
And remove these two entries from it (*)
Make sure the MongoDB collection taxonomyEntityWrapper is dropped so it will get update upon the startup
Start Mica
Add a taxonomy file

You should not see the infinite loop.

[!NOTE] * These two taxonomies are assumed to be coming from Opal by default and in your case, there is no Opal.

We need to investigate more and find a non-breaking solution.

ymarcon commented 9 months ago

Fixed in 5.2.3

johannes-darms commented 9 months ago

Problem is resolved. Many thanks!

obiba / mica2