Index Not Found Exception for Genomics API

[juliamullen]

For an automatically created build genomics_api_202110061126_qfg5kwup the following output is displayed:

NotFoundError(404, 'index_not_found_exception', 'no such index', genomics_api_202110061126_qfg5kwup, index_or_alias)

Creating a new release by going through the "New release" modal seems to have bypassed the issue.

[juliamullen]

relevant log dump:
11:35:40 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Step name='pre' indexer=>
11:35:40 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- ('Created', 'genomics_api_202110061126_qfg5kwup', {'acknowledged': True, 'shards_acknowledged': True, 'index': 'genomics_api_202110061126_qfg5kwup'})
11:35:40 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- IndexerStepResult({'host': 'su03:9200', 'environment': 'auto'})
11:35:40 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- IndexerCumulativeResult({'host': 'su03:9200', 'environment': 'auto'})
11:35:40 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Step name='index' indexer=>
11:35:40 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- Fetch _ids from 'genomics_api_202110061126_qfg5kwup', and create indexer job with batch_size=10000.
11:35:40 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - WARNING -- Can't find information for target collection 'genomics_api_202110061126_qfg5kwup'
11:35:40 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - DEBUG -- No cache file found (or invalid) for 'genomics_api_202110061126_qfg5kwup', use doc_feeder
11:35:40 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- Building cache file '/data/outbreak/cache/genomics_api_202110061126_qfg5kwup.xz._tmp_8la1SmZx'
11:35:40 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Schedule running, on batch #1/401 0.2%, total=4006934 scheduled=10000 finished=0>
11:35:40 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Schedule running, on batch #2/401 0.5%, total=4006934 scheduled=20000 finished=0>
11:35:40 [553725:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- #1: 10000 documents.
11:35:40 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Schedule running, on batch #3/401 0.7%, total=4006934 scheduled=30000 finished=0>
11:35:40 [553727:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- #2: 10000 documents.
11:35:40 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Schedule running, on batch #4/401 1.0%, total=4006934 scheduled=40000 finished=0>
11:35:40 [553726:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- #3: 10000 documents.
11:35:40 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Schedule running, on batch #5/401 1.2%, total=4006934 scheduled=50000 finished=0>
11:35:40 [553728:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- #4: 10000 documents.
11:35:40 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Schedule running, on batch #6/401 1.5%, total=4006934 scheduled=60000 finished=0>
11:35:41 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Schedule running, on batch #7/401 1.7%, total=4006934 scheduled=70000 finished=0>
11:35:41 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Schedule running, on batch #8/401 2.0%, total=4006934 scheduled=80000 finished=0>
11:35:41 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Schedule running, on batch #9/401 2.2%, total=4006934 scheduled=90000 finished=0>
11:35:41 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Schedule running, on batch #10/401 2.5%, total=4006934 scheduled=100000 finished=0>
11:35:42 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Schedule running, on batch #11/401 2.7%, total=4006934 scheduled=110000 finished=0>
11:35:42 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Schedule running, on batch #12/401 3.0%, total=4006934 scheduled=120000 finished=0>
11:35:54 [553725:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- #5: 10000 documents.
11:35:54 [553726:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- #6: 10000 documents.
11:35:55 [553727:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- #7: 10000 documents.
11:35:56 [553728:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- #8: 10000 documents.
11:35:57 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Schedule running, on batch #13/401 3.2%, total=4006934 scheduled=130000 finished=40000>
11:35:57 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Schedule running, on batch #14/401 3.5%, total=4006934 scheduled=140000 finished=40000>
11:35:57 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Schedule running, on batch #15/401 3.7%, total=4006934 scheduled=150000 finished=40000>
11:35:58 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Schedule running, on batch #16/401 4.0%, total=4006934 scheduled=160000 finished=40000>
11:36:09 [553728:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- #9: 10000 documents.
11:36:11 [553727:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- #10: 10000 documents.
[...]
12:01:06 [553725:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- #350: 10000 documents.
12:01:06 [553726:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- #351: 10000 documents.
12:01:07 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - WARNING -- ('500 document(s) failed to index.', [{'index': {'_index': 'genomics_api_202110061126_qfg5kwup', '_type': 'mutation', '_id': 'EPI_ISL_2376799', 'status': 404, 'error': {'type': 'index_not_found_exception', 'reason': 'no such index', 'index_uuid': 'na', 'index': 'genomics_api_202110061126_qfg5kwup'},
[... 21 MB of genomics data ...]
12:01:08 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - WARNING -- NotFoundError(404, 'index_not_found_exception', 'no such index', genomics_api_202110061126_qfg5kwup, index_or_alias)
12:01:08 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - WARNING -- NotFoundError(404, 'index_not_found_exception', 'no such index', genomics_api_202110061126_qfg5kwup, index_or_alias)
12:01:08 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - WARNING -- NotFoundError(404, 'index_not_found_exception', 'no such index', genomics_api_202110061126_qfg5kwup, index_or_alias)
12:01:08 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - WARNING -- NotFoundError(404, 'index_not_found_exception', 'no such index', genomics_api_202110061126_qfg5kwup, index_or_alias)
12:01:08 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - WARNING -- NotFoundError(404, 'index_not_found_exception', 'no such index', genomics_api_202110061126_qfg5kwup, index_or_alias)
12:01:08 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - WARNING -- NotFoundError(404, 'index_not_found_exception', 'no such index', genomics_api_202110061126_qfg5kwup, index_or_alias)
12:01:08 [553728:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- #352: 10000 documents.
12:01:08 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - ERROR -- NotFoundError(404, 'index_not_found_exception', 'no such index', genomics_api_202110061126_qfg5kwup, index_or_alias)
concurrent.futures.process._RemoteTraceback:
"""
Traceback (most recent call last):
File "/usr/lib/python3.8/concurrent/futures/process.py", line 239, in _process_worker
r = call_item.fn(*call_item.args, **call_item.kwargs)
File "/opt/home/outbreak/venv/src/biothings/biothings/utils/manager.py", line 107, in func_wrapper
raise exc
File "/opt/home/outbreak/venv/src/biothings/biothings/utils/manager.py", line 94, in func_wrapper
results = func(*args, **kwargs)
File "/opt/home/outbreak/venv/src/biothings/biothings/utils/manager.py", line 122, in do_work
return func(*args, **kwargs)
File "/opt/home/outbreak/venv/src/biothings/biothings/hub/dataindex/indexer_task.py", line 120, in dispatch
return IndexingTask(
File "/opt/home/outbreak/venv/src/biothings/biothings/hub/dataindex/indexer_task.py", line 183, in dispatch
return self.index()
File "/opt/home/outbreak/venv/src/biothings/biothings/hub/dataindex/indexer_task.py", line 199, in index
return clients.es.mindex(docs)
File "/opt/home/outbreak/venv/src/biothings/biothings/hub/dataindex/indexer_task.py", line 99, in mindex
return helpers.bulk(
File "/opt/home/outbreak/venv/lib/python3.8/site-packages/elasticsearch/helpers/actions.py", line 410, in bulk
for ok, item in streaming_bulk(
File "/opt/home/outbreak/venv/lib/python3.8/site-packages/elasticsearch/helpers/actions.py", line 319, in streaming_bulk
for bulk_data, bulk_actions in _chunk_actions(
File "/opt/home/outbreak/venv/lib/python3.8/site-packages/elasticsearch/helpers/actions.py", line 155, in _chunk_actions
for action, data in actions:
File "/opt/home/outbreak/venv/src/biothings/biothings/hub/dataindex/indexer_task.py", line 93, in _action
"_type": self.doc_type,
File "/opt/home/outbreak/venv/src/biothings/biothings/hub/dataindex/indexer_task.py", line 39, in doc_type
mappings = self.client.indices.get_mapping(self.index_name)
File "/opt/home/outbreak/venv/lib/python3.8/site-packages/elasticsearch/client/utils.py", line 168, in _wrapped
return func(*args, params=params, headers=headers, **kwargs)
File "/opt/home/outbreak/venv/lib/python3.8/site-packages/elasticsearch/client/indices.py", line 448, in get_mapping
return self.transport.perform_request(
File "/opt/home/outbreak/venv/lib/python3.8/site-packages/elasticsearch/transport.py", line 415, in perform_request
raise e
File "/opt/home/outbreak/venv/lib/python3.8/site-packages/elasticsearch/transport.py", line 381, in perform_request
status, headers_response, data = connection.perform_request(
File "/opt/home/outbreak/venv/lib/python3.8/site-packages/elasticsearch/connection/http_urllib3.py", line 277, in perform_request
self._raise_error(response.status, raw_data)
File "/opt/home/outbreak/venv/lib/python3.8/site-packages/elasticsearch/connection/base.py", line 330, in _raise_error
raise HTTP_EXCEPTIONS.get(status_code, TransportError)(
elasticsearch.exceptions.NotFoundError: NotFoundError(404, 'index_not_found_exception', 'no such index', genomics_api_202110061126_qfg5kwup, index_or_alias)
"""

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
File "/opt/home/outbreak/venv/src/biothings/biothings/hub/dataindex/indexer.py", line 368, in index
dx = yield from step.execute(job_manager, **kwargs)
File "/opt/home/outbreak/venv/src/biothings/biothings/hub/dataindex/indexer.py", line 239, in execute
return (yield from coro)
File "/opt/home/outbreak/venv/src/biothings/biothings/hub/dataindex/indexer.py", line 489, in do_index
raise error
File "/opt/home/outbreak/venv/src/biothings/biothings/hub/dataindex/indexer.py", line 474, in batch_finished
schedule.finished += future.result()
File "/opt/home/outbreak/venv/src/biothings/biothings/utils/manager.py", line 751, in run
res = yield from res
File "/usr/lib/python3.8/asyncio/events.py", line 81, in _run
self._context.run(self._callback, *self._args)
File "/opt/home/outbreak/venv/src/biothings/biothings/utils/manager.py", line 741, in ran
r = f.result()
elasticsearch.exceptions.NotFoundError: NotFoundError(404, 'index_not_found_exception', 'no such index', genomics_api_202110061126_qfg5kwup, index_or_alias)
12:01:08 [553726:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- #353: 10000 documents.
14:57:31 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Step name='pre' indexer=>
14:57:31 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- ('Created', 'genomics_api_202110061126_qfg5kwup', {'acknowledged': True, 'shards_acknowledged': True, 'index': 'genomics_api_202110061126_qfg5kwup'})
14:57:31 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- IndexerStepResult({'host': 'su03:9200', 'environment': 'su03'})
14:57:31 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- IndexerCumulativeResult({'host': 'su03:9200', 'environment': 'su03'})
14:57:31 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Step name='index' indexer=>
14:57:31 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- Fetch _ids from 'genomics_api_202110061126_qfg5kwup', and create indexer job with batch_size=10000.
14:57:31 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - WARNING -- Can't find information for target collection 'genomics_api_202110061126_qfg5kwup'
14:57:31 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - DEBUG -- No cache file found (or invalid) for 'genomics_api_202110061126_qfg5kwup', use doc_feeder
14:57:31 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- Removing aborted cache file '/data/outbreak/cache/genomics_api_202110061126_qfg5kwup.xz._tmp_8la1SmZx'
14:57:31 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- Building cache file '/data/outbreak/cache/genomics_api_202110061126_qfg5kwup.xz._tmp_V31VjCgZ'
14:57:31 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Schedule running, on batch #1/401 0.2%, total=4006934 scheduled=10000 finished=0>
14:57:32 [552406:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- <Schedule running, on batch #2/401 0.5%, total=4006934 scheduled=20000 finished=0>
14:57:32 [553727:MainThread] - index_genomics_api_202110061126_qfg5kwup - INFO -- #1: 10000 documents.
[...]

[zcqian]

How many jobs were running concurrently at the time?

[juliamullen]

@zcqian I don't have info on that. The indexer was triggered automatically and, because it failed with an error, did not require a restart. I wasn't watching when this happened. Is there a way to recover this info?

[zcqian]

@juliamullen I think I was looking at the wrong thing. I'll try to figure out what's going on. The index should be on the Elasticsearch hosted on su03 right?

[juliamullen]

automatic cleanup of old or big indices was wiping index while it was being built. will confirm changing the cleanup avoids this issue and then close.