Creation of indexes fail with a 404 because a PUT happens _too soon_ #36336

I have problems creating indexes using express-cassandra. It runs the CREATE INDEX alright, however, it then tries to add the mapping with a second PUT and that fails with a 404, saying that the index doesn't exist (yet). I have a bug report on github that gives all the details and a set of files which I can use to reproduce the problem on my machine here https://github.com/elastic/elasticsearch/issues/36336

I was asked to talk about it here so here I'm.

How many indices and shards do you have in the Elasticsearch cluster? How many nodes? What is the specification of these nodes? Is there anything in the Elasticsearch logs?

Ah, I guess I should have a look at the logs... :slight_smile: and report here about it.

The rest of the info is shown in the bug report on github in great details. One node, default setup, except that it's made a NetworkTopologyStrategy instead of SimpleStrategy. The creation of the model is done by express-cassandra.

I do not see information about shard and index count in the GitHub issue. Can you please share the output of the cluster stats API? Can you also provide your Elasticsearch configuration?

1 Like

The concerned logs are probably the following. I'll post an attachment to the git report for completeness there and also for additional logs before and after this point.

2018-12-04 20:46:38,558 ERROR [Native-Transport-Requests-2] ElasticSecondaryIndex.java:487 addField submapper not found for nested field [sha1]
2018-12-04 20:46:38,559 INFO  [Native-Transport-Requests-2] ElasticSecondaryIndex.java:461 addField updating mapping={"contentversion":{"properties":{"hashes":{"type":"nested","cql_struct":"map","cql_collection":"singleton","properties":{"sha256":{"type":"keyword"}}}}}}
2018-12-04 20:47:08,560 ERROR [Native-Transport-Requests-2] ElasticSecondaryIndex.java:470 addField error while updating mapping
org.elasticsearch.ElasticsearchTimeoutException: blocking update timeout
	at org.elasticsearch.cluster.service.ClusterService$BlockingActionListener.waitForUpdate(ClusterService.java:1974)
	at org.elasticsearch.cluster.service.ClusterService.blockingMappingUpdate(ClusterService.java:2013)
	at org.elassandra.index.ElasticSecondaryIndex.addField(ElasticSecondaryIndex.java:463)
	at org.elassandra.index.ElasticSecondaryIndex$ImmutableMappingInfo$RowcumentIndexer$Rowcument.buildContext(ElasticSecondaryIndex.java:2074)
	at org.elassandra.index.ElasticSecondaryIndex$ImmutableMappingInfo$SkinnyRowcumentIndexer$SkinnyRowcument.buildContext(ElasticSecondaryIndex.java:1623)
	at org.elassandra.index.ElasticSecondaryIndex$ImmutableMappingInfo$RowcumentIndexer$Rowcument.index(ElasticSecondaryIndex.java:2160)
	at org.elassandra.index.ElasticSecondaryIndex$ImmutableMappingInfo$RowcumentIndexer$Rowcument.index(ElasticSecondaryIndex.java:2144)
	at org.elassandra.index.ElasticSecondaryIndex$ImmutableMappingInfo$SkinnyRowcumentIndexer$SkinnyRowcument.index(ElasticSecondaryIndex.java:1623)
	at org.elassandra.index.ElasticSecondaryIndex$ImmutableMappingInfo$RowcumentIndexer$Rowcument.write(ElasticSecondaryIndex.java:2127)
	at org.elassandra.index.ElasticSecondaryIndex$ImmutableMappingInfo$SkinnyRowcumentIndexer$SkinnyRowcument.write(ElasticSecondaryIndex.java:1623)
	at org.elassandra.index.ElasticSecondaryIndex$ImmutableMappingInfo$SkinnyRowcumentIndexer.update(ElasticSecondaryIndex.java:1664)
	at org.elassandra.index.ElasticSecondaryIndex$ImmutableMappingInfo$RowcumentIndexer.finish(ElasticSecondaryIndex.java:1845)
	at org.apache.cassandra.index.SecondaryIndexManager$WriteTimeTransaction.commit(SecondaryIndexManager.java:983)
	at org.apache.cassandra.db.partitions.AtomicBTreePartition.addAllWithSizeDelta(AtomicBTreePartition.java:181)
	at org.apache.cassandra.db.Memtable.put(Memtable.java:282)
	at org.apache.cassandra.db.ColumnFamilyStore.apply(ColumnFamilyStore.java:1342)
	at org.apache.cassandra.db.Keyspace.applyInternal(Keyspace.java:631)
	at org.apache.cassandra.db.Keyspace.apply(Keyspace.java:475)
	at org.apache.cassandra.db.Mutation.apply(Mutation.java:227)
	at org.apache.cassandra.db.Mutation.apply(Mutation.java:232)
	at org.apache.cassandra.db.Mutation.apply(Mutation.java:241)
	at org.apache.cassandra.service.StorageProxy$8.runMayThrow(StorageProxy.java:1411)
	at org.apache.cassandra.service.StorageProxy$LocalMutationRunnable.run(StorageProxy.java:2650)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at org.apache.cassandra.concurrent.AbstractLocalAwareExecutorService$FutureTask.run(AbstractLocalAwareExecutorService.java:162)
	at org.apache.cassandra.concurrent.AbstractLocalAwareExecutorService$LocalSessionFutureTask.run(AbstractLocalAwareExecutorService.java:134)
	at org.apache.cassandra.concurrent.SEPExecutor.maybeExecuteImmediately(SEPExecutor.java:194)
	at org.apache.cassandra.service.StorageProxy.performLocally(StorageProxy.java:1405)
	at org.apache.cassandra.service.StorageProxy.sendToHintedEndpoints(StorageProxy.java:1312)
	at org.apache.cassandra.service.StorageProxy$2.apply(StorageProxy.java:140)
	at org.apache.cassandra.service.StorageProxy.performWrite(StorageProxy.java:1095)
	at org.apache.cassandra.service.StorageProxy.mutate(StorageProxy.java:634)
	at org.apache.cassandra.service.StorageProxy.mutateWithTriggers(StorageProxy.java:864)
	at org.apache.cassandra.cql3.statements.ModificationStatement.executeWithoutCondition(ModificationStatement.java:439)
	at org.apache.cassandra.cql3.statements.ModificationStatement.execute(ModificationStatement.java:425)
	at org.apache.cassandra.cql3.QueryProcessor.processStatement(QueryProcessor.java:224)
	at org.apache.cassandra.cql3.QueryProcessor.processPrepared(QueryProcessor.java:530)
	at org.apache.cassandra.cql3.QueryProcessor.processPrepared(QueryProcessor.java:507)
	at org.apache.cassandra.transport.messages.ExecuteMessage.execute(ExecuteMessage.java:146)
	at org.apache.cassandra.transport.Message$Dispatcher.channelRead0(Message.java:517)
	at org.apache.cassandra.transport.Message$Dispatcher.channelRead0(Message.java:410)
	at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:105)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:38)
	at io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:353)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at org.apache.cassandra.concurrent.AbstractLocalAwareExecutorService$FutureTask.run(AbstractLocalAwareExecutorService.java:162)
	at org.apache.cassandra.concurrent.SEPWorker.run(SEPWorker.java:109)
	at java.lang.Thread.run(Thread.java:745)

That is not at all what I asked for. It is probably better to add the relevant information here where the discussion is taking place. If the data does not for you can e.g. link to a gist.

Hmmm... I see... By default there is no log path in the elasticsearch yaml. However, I tried to add a path and I still only see a system.log file. In that file some of the entries are specific to elasticsearch, as far as I can tell:

org.elasticsearch.ElasticsearchTimeoutException: blocking update timeout
	at org.elasticsearch.cluster.service.ClusterService$BlockingActionListener.waitForUpdate(ClusterService.java:1974)
	at org.elasticsearch.cluster.service.ClusterService.blockingMappingUpdate(ClusterService.java:2013)

So I'm not too sure what wrong with my file on github.

As for the shards & nodes, there is one. Just one node and one shard. As for the number of indices, I have a script in the github bug report which is what I used to demonstrate the problem. It creates 3 indices, one per table.

For the setup, I did not edit anything from what I recall. So what's found in this tarball:

elassandra-6.2.3.7.tar.gz

is what I use. Maybe I should be using a newer version, though. I'm not too sure why I used that one. Probably because express-cassandra pointed to it specifically. That being said, I'd be really surprised that the newer version would just have fixed this 404 Index not Found error.

The topology strategy is setup by express-cassandra to NetworkTopologyStrategy when it creates my keyspace. I did not make edits to the files to change that or the IPs, etc. Also I use the default DC1 definition. Really nothing extraordinary.

Okay, I uploaded additional files in the git issue. https://github.com/elastic/elasticsearch/issues/36336

Personally, I don't understand why we could not discuss this on github. But hey... this is way better than a mailing list at least. :smile:

I think I uploaded everything you asked for at this point. The logs do include references to elasticsearch but I do not see any other file. So I guess that means the electricsearch logs are empty. Maybe there is a log level I could tweak?

It's a way-we-work sort of thing. GitHub works well for tracking actionable things that need changes to the codebase, but the volume of questions that don't need such action is too high to deal with everything there. Unfortunately we have to be kinda strict to manage the volume, and sometimes we guess wrong and have to move discussion back again when an actionable item comes up.

In this case I redirected you here because the Elasticsearch test suite has very many tests that do something very similar to what you are doing here, without this kind of failure, which strongly suggests a problem in your configuration or environment and not something that needs changing in Elasticsearch itself.

Your stack trace leads us here:

This is not Elasticsearch code, despite its package being org.elasticsearch...., this is something that's been added by Elassandra. It seems to be timing out, causing the index creation request to return before the index has been properly created. In fact this whole 3000-line class looks like Elassandra code, the Elasticsearch code that it replaces is renamed here: https://github.com/strapdata/elassandra/blob/a9490ffe8653bfff0b215207ac8b3490ffa3fc51/server/src/main/java/org/elasticsearch/cluster/service/BaseClusterService.java

2 Likes

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.