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

[AlexisWilke]

Elasticsearch version: 6.2.3.7

Plugins installed: none

JVM version:

java version "1.8.0_91"
Java(TM) SE Runtime Environment (build 1.8.0_91-b14)
Java HotSpot(TM) 64-Bit Server VM (build 25.91-b14, mixed mode)

OS version:

Latest of Ubuntu 16.04

Linux tristan 4.4.0-140-generic #166-Ubuntu SMP Wed Nov 14 20:09:47 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

Description of the problem including expected versus actual behavior:

I use express-cassandra to manage one Elassandra node. While testing, I like to reset my database over and over again. So I stop the running instance, delete the data folder, and restart Elassandra many times.

My installation has just 3 models and yet when I run my code that creates those three models, I get a 404 about a missing index. If you look at the sequence of commands generated in the elasticsearch/src/lib/transport.js file, we can see that the PUT ... used to create the index exists, only the code attempting to setup the mapping fails saying that one of those indexes is missing.

To see the commands sent to the REST interface of ElasticSearch, I added the following around line 213 of transport.js:

console.log('----------------------------- elasticsearch request')
console.log(params.req)

The output of which is shown in the Logs section below.

Just an idea, but it looks to me as if the code was running in parallel and that could be what causes the problem. Not the parallelism itself, but the fact that it slows down everything and timings are out of whack giving the system a chance to send the PUT ... for the mapping too soon. On the other hand, if you return a positive response before a newly created index is accessible, it's definitely asking for trouble.

Steps to reproduce:

Here is my CQL schema:

CREATE KEYSPACE my_search WITH replication = {'class': 'NetworkTopologyStrategy', 'DC1': '1'}  AND durable_writes = true;

CREATE TABLE my_search.table1 (
    id uuid PRIMARY KEY,
    authenticated boolean,
    date timestamp,
    data text
) WITH bloom_filter_fp_chance = 0.01
    AND caching = {'keys': 'ALL', 'rows_per_partition': 'NONE'}
    AND comment = ''
    AND compaction = {'class': 'org.apache.cassandra.db.compaction.SizeTieredCompactionStrategy', 'max_threshold': '32', 'min_threshold': '4'}
    AND compression = {'chunk_length_in_kb': '64', 'class': 'org.apache.cassandra.io.compress.LZ4Compressor'}
    AND crc_check_chance = 1.0
    AND dclocal_read_repair_chance = 0.1
    AND default_time_to_live = 0
    AND gc_grace_seconds = 864000
    AND max_index_interval = 2048
    AND memtable_flush_period_in_ms = 0
    AND min_index_interval = 128
    AND read_repair_chance = 0.0
    AND speculative_retry = '99PERCENTILE';

CREATE TABLE my_search.table2 (
    id uuid PRIMARY KEY,
    ref uuid,
    name text,
    value text
) WITH bloom_filter_fp_chance = 0.01
    AND caching = {'keys': 'ALL', 'rows_per_partition': 'NONE'}
    AND comment = ''
    AND compaction = {'class': 'org.apache.cassandra.db.compaction.SizeTieredCompactionStrategy', 'max_threshold': '32', 'min_threshold': '4'}
    AND compression = {'chunk_length_in_kb': '64', 'class': 'org.apache.cassandra.io.compress.LZ4Compressor'}
    AND crc_check_chance = 1.0
    AND dclocal_read_repair_chance = 0.1
    AND default_time_to_live = 0
    AND gc_grace_seconds = 864000
    AND max_index_interval = 2048
    AND memtable_flush_period_in_ms = 0
    AND min_index_interval = 128
    AND read_repair_chance = 0.0
    AND speculative_retry = '99PERCENTILE';

CREATE TABLE my_search.table3 (
    id uuid PRIMARY KEY,
    data text,
    ref uuid,
    date timestamp,
    info map<text, text>
) WITH bloom_filter_fp_chance = 0.01
    AND caching = {'keys': 'ALL', 'rows_per_partition': 'NONE'}
    AND comment = ''
    AND compaction = {'class': 'org.apache.cassandra.db.compaction.SizeTieredCompactionStrategy', 'max_threshold': '32', 'min_threshold': '4'}
    AND compression = {'chunk_length_in_kb': '64', 'class': 'org.apache.cassandra.io.compress.LZ4Compressor'}
    AND crc_check_chance = 1.0
    AND dclocal_read_repair_chance = 0.1
    AND default_time_to_live = 0
    AND gc_grace_seconds = 864000
    AND max_index_interval = 2048
    AND memtable_flush_period_in_ms = 0
    AND min_index_interval = 128
    AND read_repair_chance = 0.0
    AND speculative_retry = '99PERCENTILE';

And here is my script that runs cqlsh to create the schema and immediately runs the various GET, HEAD, PUT commands pretty much the same way as express-cassandra does.

(Obviously express-cassandra uses the HEAD to know what to do next, my script here just doesn't check anything. It expects the database to be brand new i.e. if not brand new, stop the database, delete the data folder if it exists, and restart the database, wait for it to be up and ready, then start this script.)

#!/bin/sh

contrib/elassandra-6.2.3.7/bin/cqlsh -f tmp/schema.cql

curl -XGET 'http://127.0.0.1:9200/_nodes/_all/http?filter_path=nodes.*.http.publish_address,nodes.*.name,nodes.*.hostname,nodes.*.host,nodes.*.version' ; echo

curl --head 'http://127.0.0.1:9200/my_search' ; echo
curl -XPUT -H 'Content-Type: application/json' 'http://localhost:9200/my_search' -d '{"settings":{"keyspace":"my_search","index":{"number_of_shards":"1"}},"index":{"number_of_shards":1}}' ; echo

(
curl --head 'http://127.0.0.1:9200/my_search_table1' ; echo
curl -XPUT -H 'Content-Type: application/json' 'http://localhost:9200/my_search_table1' -d '{"settings":{"keyspace":"my_search","index":{"number_of_shards":"1"}},"index":{"number_of_shards":1}}' ; echo
curl -XPUT -H 'Content-Type: application/json' 'http://localhost:9200/my_search_table1/_mapping/table1' -d '{"properties":{"id":{"type":"keyword","cql_collection":"singleton","cql_partition_key":true,"cql_primary_key_order":0},"date":{"type":"date","cql_collection":"singleton"},"data":{"type":"text","cql_collection":"singleton","index":true},"authenticated":{"type":"boolean","cql_collection":"singleton"}}}' ; echo
)&

(
curl --head 'http://127.0.0.1:9200/my_search_table2' ; echo
curl -XPUT -H 'Content-Type: application/json' 'http://localhost:9200/my_search_table2' -d '{"settings":{"keyspace":"my_search","index":{"number_of_shards":"1"}},"index":{"number_of_shards":1}}' ; echo
curl -XPUT -H 'Content-Type: application/json' 'http://localhost:9200/my_search_table2/_mapping/table2' -d '{"properties":{"id":{"type":"keyword","cql_collection":"singleton","cql_partition_key":true,"cql_primary_key_order":0},"ref":{"type":"keyword","cql_collection":"singleton"},"name":{"type":"keyword","cql_collection":"singleton"},"value":{"type":"text","cql_collection":"singleton","index":true}}}' ; echo
)&

(
curl --head 'http://127.0.0.1:9200/my_search_table3' ; echo
curl -XPUT -H 'Content-Type: application/json' 'http://localhost:9200/my_search_table3' -d '{"settings":{"keyspace":"my_search","index":{"number_of_shards":"1"}},"index":{"number_of_shards":1}}' ; echo
curl -XPUT -H 'Content-Type: application/json' 'http://localhost:9200/my_search_table3/_mapping/table3' -d '{"properties":{"id":{"type":"keyword","cql_collection":"singleton","cql_partition_key":true,"cql_primary_key_order":0},"ref":{"type":"keyword","cql_collection":"singleton"},"date":{"type":"date","cql_collection":"singleton"},"data":{"type":"text","cql_collection":"singleton","index":true}}}' ; echo
)&

wait

IMPORTANT NOTE: In my express-cassandra code I setup all timeout values to 1h instead of the various defaults it uses (12 to 30 seconds) to at least I can avoid time outs.

Logs:

note: this is the log from my actual software, opposed to the logs I would get from the script above. The order may vary and which table index generates the 404 error(s) may vary as well.

----------------------------- elasticsearch request
{ method: 'GET',
  path: '/_nodes/_all/http',
  query:
   { filter_path:
      'nodes.*.http.publish_address,nodes.*.name,nodes.*.hostname,nodes.*.host,nodes.*.version' },
  body: undefined,
  headers: {} }
----------------------------- elasticsearch request
{ method: 'HEAD',
  path: '/my_search',
  query: {},
  body: undefined,
  headers: {} }
----------------------------- elasticsearch request
{ method: 'PUT',
  path: '/my_search',
  query: {},
  body:
   '{"settings":{"keyspace":"my_search","index":{"number_of_shards":"1"}},"index":{"number_of_shards":1}}',
  headers: { 'content-type': 'application/json' } }
----------------------------- elasticsearch request
{ method: 'HEAD',
  path: '/my_search_table1',
  query: {},
  body: undefined,
  headers: {} }
----------------------------- elasticsearch request
{ method: 'PUT',
  path: '/my_search_table1',
  query: {},
  body:
   '{"settings":{"keyspace":"my_search","index":{"number_of_shards":"1"}},"index":{"number_of_shards":1}}',
  headers: { 'content-type': 'application/json' } }
----------------------------- elasticsearch request
{ method: 'PUT',
  path: '/my_search_table1/_mapping/table1',
  query: {},
  body:
   '{"properties":{"primary_key":{"type":"keyword","cql_collection":"singleton","cql_partition_key":true,"cql_primary_key_order":0},"created_date":{"type":"date","cql_collection":"singleton"},"url":{"type":"text","cql_collection":"singleton","index":true},"authenticated":{"type":"boolean","cql_collection":"singleton"}}}',
  headers: { 'content-type': 'application/json' } }
----------------------------- elasticsearch request
{ method: 'HEAD',
  path: '/my_search_table2',
  query: {},
  body: undefined,
  headers: {} }
----------------------------- elasticsearch request
{ method: 'PUT',
  path: '/my_search_table2',
  query: {},
  body:
   '{"settings":{"keyspace":"my_search","index":{"number_of_shards":"1"}},"index":{"number_of_shards":1}}',
  headers: { 'content-type': 'application/json' } }
----------------------------- elasticsearch request
{ method: 'HEAD',
  path: '/my_search_table3',
  query: {},
  body: undefined,
  headers: {} }
----------------------------- elasticsearch request
{ method: 'PUT',
  path: '/my_search_table3',
  query: {},
  body:
   '{"settings":{"keyspace":"my_search","index":{"number_of_shards":"1"}},"index":{"number_of_shards":1}}',
  headers: { 'content-type': 'application/json' } }
----------------------------- elasticsearch request
{ method: 'PUT',
  path: '/my_search_table2/_mapping/table2',
  query: {},
  body:
   '{"properties":{"id":{"type":"keyword","cql_collection":"singleton","cql_partition_key":true,"cql_primary_key_order":0},"ref":{"type":"keyword","cql_collection":"singleton"},"name":{"type":"keyword","cql_collection":"singleton"},"value":{"type":"text","cql_collection":"singleton","index":true}}}',
  headers: { 'content-type': 'application/json' } }
{ Error: [index_not_found_exception] no such index, with { resource.type="index_or_alias" & resource.id="my_search_table2" & index_uuid="_na_" & index="my_search_table2" }
    at respond (.../my_search/node_modules/elasticsearch/src/lib/transport.js:310:15)
    at checkRespForFailure (.../my_search/node_modules/elasticsearch/src/lib/transport.js:269:7)
    at HttpConnector.<anonymous> (.../my_search/node_modules/elasticsearch/src/lib/connectors/http.js:165:7)
    at IncomingMessage.wrapper (.../my_search/node_modules/lodash/lodash.js:4935:19)
    at IncomingMessage.emit (events.js:187:15)
    at endReadableNT (_stream_readable.js:1094:12)
    at process._tickCallback (internal/process/next_tick.js:63:19)
  status: 404,
  displayName: 'NotFound',
  message:
   '[index_not_found_exception] no such index, with { resource.type="index_or_alias" & resource.id="my_search_table2" & index_uuid="_na_" & index="my_search_table2" }',
  path: '/my_search_table2/_mapping/table2',
  query: {},
  body:
   '{"properties":{"id":{"type":"keyword","cql_collection":"singleton","cql_partition_key":true,"cql_primary_key_order":0},"ref":{"type":"keyword","cql_collection":"singleton"},"name":{"type":"keyword","cql_collection":"singleton"},"value":{"type":"text","cql_collection":"singleton","index":true}}}',
  statusCode: 404,
  response:
   '{"error":{"root_cause":[{"type":"index_not_found_exception","reason":"no such index","resource.type":"index_or_alias","resource.id":"my_search_table2","index_uuid":"_na_","index":"my_search_table2"}],"type":"index_not_found_exception","reason":"no such index","resource.type":"index_or_alias","resource.id":"my_search_table2","index_uuid":"_na_","index":"my_search_table2"},"status":404}',
  toString: [Function],
  toJSON: [Function] }

[DaveCTurner]

There is something funny going on here, because with default settings I think what you're doing should be fine, although I think it is possible to get this to happen by reducing some timeouts to unreasonably low values. I ran hundreds of iterations of a test that does what you are doing without a failure, with default settings.

It's probably best to ask this kind of question in the discussion forum rather than here. I don't think there's any action to be taken in this repository, so I'm closing this. Please link to your post here so other readers can follow along. If we manage to identify a bug in the forum then we can reopen this.

[AlexisWilke]

Here is a log as requested by Christian on the discussion forum.

logs.txt

[AlexisWilke]

Here is the output of the cluster stats command:

stats.txt

To be clear, I mention above that I have ONE node and ONE shard. I'm still at the early stages testing, getting things together. It is harder when you can't just run scripts to test everything from scratch again and again, though.

The configuration files come straight from Elassandra version 6.2.3.7. I just tried to set the path to the logs directory to get some ElectricSearch logs, but I got no other files than the default system.log generated by Cassandra.

elasticsearch.yml.txt

and:

cassandra.yaml.txt

[DaveCTurner]

@AlexisWilke it's best to keep this discussion in one place, no need to duplicate things here like this. I'll respond on the forum. If anyone else is following along, the thread is at https://discuss.elastic.co/t/creation-of-indexes-fail-with-a-404-because-a-put-happens-too-soon-36336/160020/8